From da63ed06eb53a76ee2d42c737e53333ca19a0271 Mon Sep 17 00:00:00 2001 From: ajlopez Date: Sat, 24 Apr 2021 20:16:29 -0300 Subject: [PATCH 1/8] TrieStoreImpl and DataSourceWithCache additional logs --- .../main/java/co/rsk/trie/TrieStoreImpl.java | 20 +++++++++++++- .../datasource/DataSourceWithCache.java | 27 ++++++++++++++++++- 2 files changed, 45 insertions(+), 2 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index 7c9b63d56fb..9fae65ec54b 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -18,6 +18,7 @@ package co.rsk.trie; +import org.ethereum.datasource.DataSourceWithCache; import org.ethereum.datasource.KeyValueDataSource; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -46,6 +47,10 @@ public class TrieStoreImpl implements TrieStore { private Set savedTries = Collections .newSetFromMap(Collections.synchronizedMap(new WeakHashMap<>())); + private int noRetrieves; + private int noSaves; + private int noNoSaves; + public TrieStoreImpl(KeyValueDataSource store) { this.store = store; } @@ -55,9 +60,17 @@ public TrieStoreImpl(KeyValueDataSource store) { */ @Override public void save(Trie trie) { + noRetrieves = 0; + noSaves = 0; + noNoSaves = 0; + logger.trace("Start saving trie root."); save(trie, true, 0); - logger.trace("End saving trie root."); + logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrieves, noSaves, noNoSaves); + + if (store instanceof DataSourceWithCache) { + ((DataSourceWithCache)store).emitLogs(); + } } /** @@ -67,9 +80,12 @@ private void save(Trie trie, boolean forceSaveRoot, int level) { logger.trace("Start saving trie, level : {}", level); if (savedTries.contains(trie)) { // it is guaranteed that the children of a saved node are also saved + noNoSaves++; return; } + noSaves++; + byte[] trieKeyBytes = trie.getHash().getBytes(); if (forceSaveRoot && this.store.get(trieKeyBytes) != null) { @@ -122,6 +138,8 @@ public Optional retrieve(byte[] hash) { return Optional.empty(); } + noRetrieves++; + Trie trie = Trie.fromMessage(message, this); savedTries.add(trie); return Optional.of(trie); diff --git a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java index c2ce5c1c84c..1affe0fb73f 100644 --- a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java +++ b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java @@ -31,7 +31,7 @@ import java.util.stream.Stream; public class DataSourceWithCache implements KeyValueDataSource { - private static final Logger logger = LoggerFactory.getLogger(DataSourceWithCache.class); + private static final Logger logger = LoggerFactory.getLogger("datasourcewithcache"); private final int cacheSize; private final KeyValueDataSource base; @@ -40,6 +40,10 @@ public class DataSourceWithCache implements KeyValueDataSource { private final ReentrantReadWriteLock lock = new ReentrantReadWriteLock(); + private int noPuts; + private int noGets; + private int noGetsFromStore; + public DataSourceWithCache(KeyValueDataSource base, int cacheSize) { this.cacheSize = cacheSize; this.base = base; @@ -55,6 +59,8 @@ public byte[] get(byte[] key) { this.lock.readLock().lock(); + noGets++; + try { if (committedCache.containsKey(wrappedKey)) { return committedCache.get(wrappedKey); @@ -66,6 +72,8 @@ public byte[] get(byte[] key) { value = base.get(key); + noGetsFromStore++; + //null value, as expected, is allowed here to be stored in committedCache committedCache.put(wrappedKey, value); } @@ -80,6 +88,8 @@ public byte[] get(byte[] key) { public byte[] put(byte[] key, byte[] value) { ByteArrayWrapper wrappedKey = ByteUtil.wrap(key); + noPuts++; + return put(wrappedKey, value); } @@ -254,4 +264,19 @@ public void close() { this.lock.writeLock().unlock(); } } + + public void emitLogs() { + this.lock.writeLock().lock(); + + try { + logger.trace("Activity: No. Gets: {}. No. Puts: {}. No. Gets from Store: {}", noGets, noPuts, noGetsFromStore); + + noGetsFromStore = 0; + noGets = 0; + noPuts = 0; + } + finally { + this.lock.writeLock().unlock(); + } + } } From 529e44ed26f0221284634b353bb898b34d23cfe8 Mon Sep 17 00:00:00 2001 From: ajlopez Date: Sat, 24 Apr 2021 20:34:24 -0300 Subject: [PATCH 2/8] Improving Trie node retrieve and save --- .../main/java/co/rsk/trie/NodeReference.java | 5 +++ rskj-core/src/main/java/co/rsk/trie/Trie.java | 24 ++++++++++++-- .../main/java/co/rsk/trie/TrieStoreImpl.java | 31 ++++++++++--------- 3 files changed, 44 insertions(+), 16 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/NodeReference.java b/rskj-core/src/main/java/co/rsk/trie/NodeReference.java index 1c0eff0c40f..e62f8826364 100644 --- a/rskj-core/src/main/java/co/rsk/trie/NodeReference.java +++ b/rskj-core/src/main/java/co/rsk/trie/NodeReference.java @@ -106,6 +106,11 @@ public boolean isEmbeddable() { } + // the referenced node was loaded + public boolean wasLoaded() { + return lazyNode != null; + } + // This method should only be called from save() public int serializedLength() { if (!isEmpty()) { diff --git a/rskj-core/src/main/java/co/rsk/trie/Trie.java b/rskj-core/src/main/java/co/rsk/trie/Trie.java index e17bc0b3ad8..98437e78b07 100644 --- a/rskj-core/src/main/java/co/rsk/trie/Trie.java +++ b/rskj-core/src/main/java/co/rsk/trie/Trie.java @@ -103,6 +103,9 @@ public class Trie { // associated store, to store or retrieve nodes in the trie private TrieStore store; + // already saved in store flag + private boolean saved; + // shared Path private final TrieKeySlice sharedPath; @@ -151,7 +154,10 @@ public static Trie fromMessage(byte[] message, TrieStore store) { trie = fromMessageRskip107(ByteBuffer.wrap(message), store); } + trie.saved = true; + profiler.stop(metric); + return trie; } @@ -232,7 +238,10 @@ private static Trie fromMessageOrchid(byte[] message, TrieStore store) { } // it doesn't need to clone value since it's retrieved from store or created from message - return new Trie(store, sharedPath, value, left, right, lvalue, valueHash); + Trie trie = new Trie(store, sharedPath, value, left, right, lvalue, valueHash); + trie.saved = true; + + return trie; } private static Trie fromMessageRskip107(ByteBuffer message, TrieStore store) { @@ -320,7 +329,10 @@ private static Trie fromMessageRskip107(ByteBuffer message, TrieStore store) { throw new IllegalArgumentException("The message had more data than expected"); } - return new Trie(store, sharedPath, value, left, right, lvalue, valueHash, childrenSize); + Trie trie = new Trie(store, sharedPath, value, left, right, lvalue, valueHash, childrenSize); + trie.saved = true; + + return trie; } /** @@ -1435,4 +1447,12 @@ private List findNodes(TrieKeySlice key) { return subnodes; } + + public boolean wasSaved() { + return this.saved; + } + + public void saved() { + this.saved = true; + } } diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index 9fae65ec54b..d4971d771b2 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -43,10 +43,6 @@ public class TrieStoreImpl implements TrieStore { private KeyValueDataSource store; - /** Weak references are removed once the tries are garbage collected */ - private Set savedTries = Collections - .newSetFromMap(Collections.synchronizedMap(new WeakHashMap<>())); - private int noRetrieves; private int noSaves; private int noNoSaves; @@ -77,13 +73,12 @@ public void save(Trie trie) { * @param forceSaveRoot allows saving the root node even if it's embeddable */ private void save(Trie trie, boolean forceSaveRoot, int level) { - logger.trace("Start saving trie, level : {}", level); - if (savedTries.contains(trie)) { - // it is guaranteed that the children of a saved node are also saved - noNoSaves++; + if (trie.wasSaved()) { return; } + logger.trace("Start saving trie, level : {}", level); + noSaves++; byte[] trieKeyBytes = trie.getHash().getBytes(); @@ -94,10 +89,19 @@ private void save(Trie trie, boolean forceSaveRoot, int level) { return; } - logger.trace("Start left trie. Level: {}", level); - trie.getLeft().getNode().ifPresent(t -> save(t, false, level + 1)); - logger.trace("Start right trie. Level: {}", level); - trie.getRight().getNode().ifPresent(t -> save(t, false, level + 1)); + NodeReference leftNodeReference = trie.getLeft(); + + if (leftNodeReference.wasLoaded()) { + logger.trace("Start left trie. Level: {}", level); + leftNodeReference.getNode().ifPresent(t -> save(t, false, level + 1)); + } + + NodeReference rightNodeReference = trie.getRight(); + + if (rightNodeReference.wasLoaded()) { + logger.trace("Start right trie. Level: {}", level); + rightNodeReference.getNode().ifPresent(t -> save(t, false, level + 1)); + } if (trie.hasLongValue()) { // Note that there is no distinction in keys between node data and value data. This could bring problems in @@ -121,8 +125,8 @@ private void save(Trie trie, boolean forceSaveRoot, int level) { logger.trace("Putting in store trie root."); this.store.put(trieKeyBytes, trie.toMessage()); + trie.saved(); logger.trace("End putting in store trie root."); - savedTries.add(trie); logger.trace("End Saving trie, level: {}.", level); } @@ -141,7 +145,6 @@ public Optional retrieve(byte[] hash) { noRetrieves++; Trie trie = Trie.fromMessage(message, this); - savedTries.add(trie); return Optional.of(trie); } From fd51f7b512daa8dcb7f1a93fe01ccb713eb5e27e Mon Sep 17 00:00:00 2001 From: ajlopez Date: Thu, 6 May 2021 09:20:53 -0300 Subject: [PATCH 3/8] Renaming argument to isRootNode --- rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index d4971d771b2..feabac69aa5 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -70,9 +70,9 @@ public void save(Trie trie) { } /** - * @param forceSaveRoot allows saving the root node even if it's embeddable + * @param isRootNode it is the root node of the trie */ - private void save(Trie trie, boolean forceSaveRoot, int level) { + private void save(Trie trie, boolean isRootNode, int level) { if (trie.wasSaved()) { return; } @@ -83,7 +83,7 @@ private void save(Trie trie, boolean forceSaveRoot, int level) { byte[] trieKeyBytes = trie.getHash().getBytes(); - if (forceSaveRoot && this.store.get(trieKeyBytes) != null) { + if (isRootNode && this.store.get(trieKeyBytes) != null) { // the full trie is already saved logger.trace("End saving trie, level : {}, already saved.", level); return; @@ -118,7 +118,7 @@ private void save(Trie trie, boolean forceSaveRoot, int level) { logger.trace("End Putting in store, hasLongValue. Level: {}", level); } - if (trie.isEmbeddable() && !forceSaveRoot) { + if (trie.isEmbeddable() && !isRootNode) { logger.trace("End Saving. Level: {}", level); return; } From 046647464ced166a18caaa0b07e1f8f4cfd14987 Mon Sep 17 00:00:00 2001 From: ajlopez Date: Thu, 6 May 2021 16:35:32 -0300 Subject: [PATCH 4/8] Improve TrieStoreImpl logging --- .../main/java/co/rsk/trie/TrieStoreImpl.java | 42 +++++++++++++------ 1 file changed, 29 insertions(+), 13 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index feabac69aa5..435a686d76a 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -23,10 +23,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; -import java.util.Collections; import java.util.Optional; -import java.util.Set; -import java.util.WeakHashMap; /** * TrieStoreImpl store and retrieve Trie node by hash @@ -43,9 +40,13 @@ public class TrieStoreImpl implements TrieStore { private KeyValueDataSource store; - private int noRetrieves; - private int noSaves; - private int noNoSaves; + private int noRetrievesInBlockProcess; + private int noSavesInBlockProcess; + private int noNoSavesInBlockProcess; + + private int noRetrievesInSaveTrie; + private int noSavesInSaveTrie; + private int noNoSavesInSaveTrie; public TrieStoreImpl(KeyValueDataSource store) { this.store = store; @@ -56,13 +57,18 @@ public TrieStoreImpl(KeyValueDataSource store) { */ @Override public void save(Trie trie) { - noRetrieves = 0; - noSaves = 0; - noNoSaves = 0; + noRetrievesInSaveTrie = 0; + noSavesInSaveTrie = 0; + noNoSavesInSaveTrie = 0; logger.trace("Start saving trie root."); save(trie, true, 0); - logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrieves, noSaves, noNoSaves); + logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrievesInSaveTrie, noSavesInSaveTrie, noNoSavesInSaveTrie); + logger.trace("End process block. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrievesInBlockProcess, noSavesInBlockProcess, noNoSavesInBlockProcess); + + noRetrievesInBlockProcess = 0; + noSavesInBlockProcess = 0; + noNoSavesInBlockProcess = 0; if (store instanceof DataSourceWithCache) { ((DataSourceWithCache)store).emitLogs(); @@ -79,16 +85,21 @@ private void save(Trie trie, boolean isRootNode, int level) { logger.trace("Start saving trie, level : {}", level); - noSaves++; - byte[] trieKeyBytes = trie.getHash().getBytes(); if (isRootNode && this.store.get(trieKeyBytes) != null) { // the full trie is already saved logger.trace("End saving trie, level : {}, already saved.", level); + + noNoSavesInSaveTrie++; + noNoSavesInBlockProcess++; + return; } + noSavesInSaveTrie++; + noSavesInBlockProcess++; + NodeReference leftNodeReference = trie.getLeft(); if (leftNodeReference.wasLoaded()) { @@ -138,11 +149,13 @@ public void flush(){ @Override public Optional retrieve(byte[] hash) { byte[] message = this.store.get(hash); + if (message == null) { return Optional.empty(); } - noRetrieves++; + noRetrievesInSaveTrie++; + noRetrievesInBlockProcess++; Trie trie = Trie.fromMessage(message, this); return Optional.of(trie); @@ -150,6 +163,9 @@ public Optional retrieve(byte[] hash) { @Override public byte[] retrieveValue(byte[] hash) { + noRetrievesInSaveTrie++; + noRetrievesInBlockProcess++; + return this.store.get(hash); } From 3e213f27fe39502ad424ff7943b40c67a585c5be Mon Sep 17 00:00:00 2001 From: ajlopez Date: Fri, 7 May 2021 16:47:31 -0300 Subject: [PATCH 5/8] Check State Root in ExecuteBlock --- .../src/main/java/co/rsk/cli/tools/ExecuteBlocks.java | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java b/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java index 1201ee40079..891a12fc050 100644 --- a/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java +++ b/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java @@ -19,10 +19,13 @@ import co.rsk.RskContext; import co.rsk.core.bc.BlockExecutor; +import co.rsk.core.bc.BlockResult; import co.rsk.trie.TrieStore; import org.ethereum.core.Block; import org.ethereum.db.BlockStore; +import java.util.Arrays; + /** * The entry point for execute blocks CLI tool * This is an experimental/unsupported tool @@ -46,7 +49,12 @@ public static void execute(String[] args, BlockExecutor blockExecutor, BlockStor Block block = blockStore.getChainBlockByNumber(n); Block parent = blockStore.getBlockByHash(block.getParentHash().getBytes()); - blockExecutor.execute(block, parent.getHeader(), false, false); + BlockResult blockResult = blockExecutor.execute(block, parent.getHeader(), false, false); + + if (!Arrays.equals(blockResult.getFinalState().getHash().getBytes(), block.getStateRoot())) { + System.err.println("Invalid state root block number " + n); + break; + } } trieStore.flush(); From d02486577bc8335dae5a038047bf6b5ca9beae8c Mon Sep 17 00:00:00 2001 From: Volodymyr Kravets Date: Wed, 30 Jun 2021 12:03:20 +0300 Subject: [PATCH 6/8] Addressed comments --- .../java/co/rsk/cli/tools/ExecuteBlocks.java | 13 ++- .../co/rsk/db/importer/BootstrapImporter.java | 3 +- .../main/java/co/rsk/trie/MultiTrieStore.java | 2 +- .../main/java/co/rsk/trie/NodeReference.java | 3 +- rskj-core/src/main/java/co/rsk/trie/Trie.java | 22 ++--- .../main/java/co/rsk/trie/TrieStoreImpl.java | 96 ++++++++++++------- .../datasource/DataSourceWithCache.java | 38 +++++--- .../java/co/rsk/cli/tools/CliToolsTest.java | 3 +- 8 files changed, 114 insertions(+), 66 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java b/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java index 891a12fc050..e1705fd1452 100644 --- a/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java +++ b/rskj-core/src/main/java/co/rsk/cli/tools/ExecuteBlocks.java @@ -20,6 +20,8 @@ import co.rsk.RskContext; import co.rsk.core.bc.BlockExecutor; import co.rsk.core.bc.BlockResult; +import co.rsk.crypto.Keccak256; +import co.rsk.db.StateRootHandler; import co.rsk.trie.TrieStore; import org.ethereum.core.Block; import org.ethereum.db.BlockStore; @@ -37,11 +39,13 @@ public static void main(String[] args) { BlockExecutor blockExecutor = ctx.getBlockExecutor(); BlockStore blockStore = ctx.getBlockStore(); TrieStore trieStore = ctx.getTrieStore(); - - execute(args, blockExecutor, blockStore, trieStore); + StateRootHandler stateRootHandler = ctx.getStateRootHandler(); + + execute(args, blockExecutor, blockStore, trieStore, stateRootHandler); } - public static void execute(String[] args, BlockExecutor blockExecutor, BlockStore blockStore, TrieStore trieStore) { + public static void execute(String[] args, BlockExecutor blockExecutor, BlockStore blockStore, TrieStore trieStore, + StateRootHandler stateRootHandler) { long fromBlockNumber = Long.parseLong(args[0]); long toBlockNumber = Long.parseLong(args[1]); @@ -51,7 +55,8 @@ public static void execute(String[] args, BlockExecutor blockExecutor, BlockStor BlockResult blockResult = blockExecutor.execute(block, parent.getHeader(), false, false); - if (!Arrays.equals(blockResult.getFinalState().getHash().getBytes(), block.getStateRoot())) { + Keccak256 stateRootHash = stateRootHandler.translate(block.getHeader()); + if (!Arrays.equals(blockResult.getFinalState().getHash().getBytes(), stateRootHash.getBytes())) { System.err.println("Invalid state root block number " + n); break; } diff --git a/rskj-core/src/main/java/co/rsk/db/importer/BootstrapImporter.java b/rskj-core/src/main/java/co/rsk/db/importer/BootstrapImporter.java index e6268bcfef4..924485c0787 100644 --- a/rskj-core/src/main/java/co/rsk/db/importer/BootstrapImporter.java +++ b/rskj-core/src/main/java/co/rsk/db/importer/BootstrapImporter.java @@ -35,6 +35,7 @@ import java.math.BigInteger; import java.util.ArrayList; import java.util.List; +import java.util.Objects; public class BootstrapImporter { @@ -76,7 +77,7 @@ private static void insertState(TrieStore destinationTrieStore, RLPElement rlpEl for (int k = 0; k < nodesData.size(); k++) { RLPElement element = nodesData.get(k); - byte[] rlpData = element.getRLPData(); + byte[] rlpData = Objects.requireNonNull(element.getRLPData()); Trie trie = Trie.fromMessage(rlpData, fakeStore); hashMapDB.put(trie.getHash().getBytes(), rlpData); nodes.add(trie); diff --git a/rskj-core/src/main/java/co/rsk/trie/MultiTrieStore.java b/rskj-core/src/main/java/co/rsk/trie/MultiTrieStore.java index e03dba70dbf..e73bb202c98 100644 --- a/rskj-core/src/main/java/co/rsk/trie/MultiTrieStore.java +++ b/rskj-core/src/main/java/co/rsk/trie/MultiTrieStore.java @@ -81,7 +81,7 @@ public Optional retrieve(byte[] rootHash) { if (message == null) { continue; } - return Optional.of(Trie.fromMessage(message, this)); + return Optional.of(Trie.fromMessage(message, this).markAsSaved()); } return Optional.empty(); diff --git a/rskj-core/src/main/java/co/rsk/trie/NodeReference.java b/rskj-core/src/main/java/co/rsk/trie/NodeReference.java index e62f8826364..88685ff6877 100644 --- a/rskj-core/src/main/java/co/rsk/trie/NodeReference.java +++ b/rskj-core/src/main/java/co/rsk/trie/NodeReference.java @@ -27,6 +27,7 @@ public class NodeReference { + private static final NodeReference EMPTY = new NodeReference(null, null, null); private final TrieStore store; @@ -154,6 +155,6 @@ private long nodeSize(Trie trie) { } public static NodeReference empty() { - return new NodeReference(null, null, null); + return EMPTY; } } diff --git a/rskj-core/src/main/java/co/rsk/trie/Trie.java b/rskj-core/src/main/java/co/rsk/trie/Trie.java index 98437e78b07..aa6e0c96fad 100644 --- a/rskj-core/src/main/java/co/rsk/trie/Trie.java +++ b/rskj-core/src/main/java/co/rsk/trie/Trie.java @@ -54,17 +54,18 @@ * An empty node has no subnodes and a null value */ public class Trie { - private static final int ARITY = 2; - private static final int MAX_EMBEDDED_NODE_SIZE_IN_BYTES = 44; private static final Profiler profiler = ProfilerFactory.getInstance(); + + private static final int ARITY = 2; + private static final int MAX_EMBEDDED_NODE_SIZE_IN_BYTES = 44; private static final String INVALID_ARITY = "Invalid arity"; private static final int MESSAGE_HEADER_LENGTH = 2 + Short.BYTES * 2; private static final String INVALID_VALUE_LENGTH = "Invalid value length"; // all zeroed, default hash for empty nodes - private static Keccak256 emptyHash = makeEmptyHash(); + private static final Keccak256 EMPTY_HASH = makeEmptyHash(); // this node associated value, if any private byte[] value; @@ -101,10 +102,10 @@ public class Trie { private VarInt childrenSize; // associated store, to store or retrieve nodes in the trie - private TrieStore store; + private final TrieStore store; // already saved in store flag - private boolean saved; + private volatile boolean saved; // shared Path private final TrieKeySlice sharedPath; @@ -154,8 +155,6 @@ public static Trie fromMessage(byte[] message, TrieStore store) { trie = fromMessageRskip107(ByteBuffer.wrap(message), store); } - trie.saved = true; - profiler.stop(metric); return trie; @@ -239,7 +238,6 @@ private static Trie fromMessageOrchid(byte[] message, TrieStore store) { // it doesn't need to clone value since it's retrieved from store or created from message Trie trie = new Trie(store, sharedPath, value, left, right, lvalue, valueHash); - trie.saved = true; return trie; } @@ -330,7 +328,6 @@ private static Trie fromMessageRskip107(ByteBuffer message, TrieStore store) { } Trie trie = new Trie(store, sharedPath, value, left, right, lvalue, valueHash, childrenSize); - trie.saved = true; return trie; } @@ -354,7 +351,7 @@ public Keccak256 getHash() { } if (isEmptyTrie()) { - return emptyHash.copy(); + return EMPTY_HASH.copy(); } byte[] message = this.toMessage(); @@ -373,7 +370,7 @@ public Keccak256 getHashOrchid(boolean isSecure) { } if (isEmptyTrie()) { - return emptyHash.copy(); + return EMPTY_HASH.copy(); } byte[] message = this.toMessageOrchid(isSecure); @@ -1452,7 +1449,8 @@ public boolean wasSaved() { return this.saved; } - public void saved() { + public Trie markAsSaved() { this.saved = true; + return this; } } diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index 435a686d76a..42a5070f646 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -23,6 +23,7 @@ import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import javax.annotation.Nullable; import java.util.Optional; /** @@ -38,15 +39,9 @@ public class TrieStoreImpl implements TrieStore { private static final Logger logger = LoggerFactory.getLogger("triestore"); - private KeyValueDataSource store; + private static final ThreadLocal traceInfoLocal = ThreadLocal.withInitial(TraceInfo::new); - private int noRetrievesInBlockProcess; - private int noSavesInBlockProcess; - private int noNoSavesInBlockProcess; - - private int noRetrievesInSaveTrie; - private int noSavesInSaveTrie; - private int noNoSavesInSaveTrie; + private final KeyValueDataSource store; public TrieStoreImpl(KeyValueDataSource store) { this.store = store; @@ -57,28 +52,39 @@ public TrieStoreImpl(KeyValueDataSource store) { */ @Override public void save(Trie trie) { - noRetrievesInSaveTrie = 0; - noSavesInSaveTrie = 0; - noNoSavesInSaveTrie = 0; + TraceInfo traceInfo = null; + if (logger.isTraceEnabled()) { + traceInfo = traceInfoLocal.get(); + traceInfo.noRetrievesInSaveTrie = 0; + traceInfo.noSavesInSaveTrie = 0; + traceInfo.noNoSavesInSaveTrie = 0; + + logger.trace("Start saving trie root."); + } + + // save a trie recursively + save(trie, true, 0, traceInfo); - logger.trace("Start saving trie root."); - save(trie, true, 0); - logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrievesInSaveTrie, noSavesInSaveTrie, noNoSavesInSaveTrie); - logger.trace("End process block. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", noRetrievesInBlockProcess, noSavesInBlockProcess, noNoSavesInBlockProcess); + if (traceInfo != null) { + logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", + traceInfo.noRetrievesInSaveTrie, traceInfo.noSavesInSaveTrie, traceInfo.noNoSavesInSaveTrie); + logger.trace("End process block. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", + traceInfo.noRetrievesInBlockProcess, traceInfo.noSavesInBlockProcess, traceInfo.noNoSavesInBlockProcess); - noRetrievesInBlockProcess = 0; - noSavesInBlockProcess = 0; - noNoSavesInBlockProcess = 0; + traceInfo.noRetrievesInBlockProcess = 0; + traceInfo.noSavesInBlockProcess = 0; + traceInfo.noNoSavesInBlockProcess = 0; - if (store instanceof DataSourceWithCache) { - ((DataSourceWithCache)store).emitLogs(); + if (store instanceof DataSourceWithCache) { + ((DataSourceWithCache) store).emitLogs(); + } } } /** * @param isRootNode it is the root node of the trie */ - private void save(Trie trie, boolean isRootNode, int level) { + private void save(Trie trie, boolean isRootNode, int level, @Nullable TraceInfo traceInfo) { if (trie.wasSaved()) { return; } @@ -91,27 +97,31 @@ private void save(Trie trie, boolean isRootNode, int level) { // the full trie is already saved logger.trace("End saving trie, level : {}, already saved.", level); - noNoSavesInSaveTrie++; - noNoSavesInBlockProcess++; + if (traceInfo != null) { + traceInfo.noNoSavesInSaveTrie++; + traceInfo.noNoSavesInBlockProcess++; + } return; } - noSavesInSaveTrie++; - noSavesInBlockProcess++; + if (traceInfo != null) { + traceInfo.noSavesInSaveTrie++; + traceInfo.noSavesInBlockProcess++; + } NodeReference leftNodeReference = trie.getLeft(); if (leftNodeReference.wasLoaded()) { logger.trace("Start left trie. Level: {}", level); - leftNodeReference.getNode().ifPresent(t -> save(t, false, level + 1)); + leftNodeReference.getNode().ifPresent(t -> save(t, false, level + 1, traceInfo)); } NodeReference rightNodeReference = trie.getRight(); if (rightNodeReference.wasLoaded()) { logger.trace("Start right trie. Level: {}", level); - rightNodeReference.getNode().ifPresent(t -> save(t, false, level + 1)); + rightNodeReference.getNode().ifPresent(t -> save(t, false, level + 1, traceInfo)); } if (trie.hasLongValue()) { @@ -136,7 +146,7 @@ private void save(Trie trie, boolean isRootNode, int level) { logger.trace("Putting in store trie root."); this.store.put(trieKeyBytes, trie.toMessage()); - trie.saved(); + trie.markAsSaved(); logger.trace("End putting in store trie root."); logger.trace("End Saving trie, level: {}.", level); } @@ -154,17 +164,23 @@ public Optional retrieve(byte[] hash) { return Optional.empty(); } - noRetrievesInSaveTrie++; - noRetrievesInBlockProcess++; + if (logger.isTraceEnabled()) { + TraceInfo traceInfo = traceInfoLocal.get(); + traceInfo.noRetrievesInSaveTrie++; + traceInfo.noRetrievesInBlockProcess++; + } - Trie trie = Trie.fromMessage(message, this); + Trie trie = Trie.fromMessage(message, this).markAsSaved(); return Optional.of(trie); } @Override public byte[] retrieveValue(byte[] hash) { - noRetrievesInSaveTrie++; - noRetrievesInBlockProcess++; + if (logger.isTraceEnabled()) { + TraceInfo traceInfo = traceInfoLocal.get(); + traceInfo.noRetrievesInSaveTrie++; + traceInfo.noRetrievesInBlockProcess++; + } return this.store.get(hash); } @@ -173,4 +189,18 @@ public byte[] retrieveValue(byte[] hash) { public void dispose() { store.close(); } + + /** + * This holds tracing information during execution of the {@link #save(Trie)} method. + * Should not be used when logger tracing is disabled ({@link Logger#isTraceEnabled()} is {@code false}). + */ + private static final class TraceInfo { + int noRetrievesInBlockProcess; + int noSavesInBlockProcess; + int noNoSavesInBlockProcess; + + int noRetrievesInSaveTrie; + int noSavesInSaveTrie; + int noNoSavesInSaveTrie; + } } diff --git a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java index 1affe0fb73f..b65dc2c6697 100644 --- a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java +++ b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java @@ -26,6 +26,7 @@ import org.slf4j.LoggerFactory; import java.util.*; +import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.locks.ReentrantReadWriteLock; import java.util.stream.Collectors; import java.util.stream.Stream; @@ -40,9 +41,9 @@ public class DataSourceWithCache implements KeyValueDataSource { private final ReentrantReadWriteLock lock = new ReentrantReadWriteLock(); - private int noPuts; - private int noGets; - private int noGetsFromStore; + private final AtomicInteger noPuts = new AtomicInteger(); + private final AtomicInteger noGets = new AtomicInteger(); + private final AtomicInteger noGetsFromStore = new AtomicInteger(); public DataSourceWithCache(KeyValueDataSource base, int cacheSize) { this.cacheSize = cacheSize; @@ -54,13 +55,13 @@ public DataSourceWithCache(KeyValueDataSource base, int cacheSize) { @Override public byte[] get(byte[] key) { Objects.requireNonNull(key); + + boolean traceEnabled = logger.isTraceEnabled(); ByteArrayWrapper wrappedKey = ByteUtil.wrap(key); byte[] value; this.lock.readLock().lock(); - noGets++; - try { if (committedCache.containsKey(wrappedKey)) { return committedCache.get(wrappedKey); @@ -72,12 +73,18 @@ public byte[] get(byte[] key) { value = base.get(key); - noGetsFromStore++; + if (traceEnabled) { + noGetsFromStore.incrementAndGet(); + } //null value, as expected, is allowed here to be stored in committedCache committedCache.put(wrappedKey, value); } finally { + if (traceEnabled) { + noGets.incrementAndGet(); + } + this.lock.readLock().unlock(); } @@ -88,8 +95,6 @@ public byte[] get(byte[] key) { public byte[] put(byte[] key, byte[] value) { ByteArrayWrapper wrappedKey = ByteUtil.wrap(key); - noPuts++; - return put(wrappedKey, value); } @@ -110,6 +115,10 @@ private byte[] put(ByteArrayWrapper wrappedKey, byte[] value) { this.putKeyValue(wrappedKey, value); } finally { + if (logger.isTraceEnabled()) { + noPuts.incrementAndGet(); + } + this.lock.writeLock().unlock(); } @@ -266,14 +275,17 @@ public void close() { } public void emitLogs() { + if (!logger.isTraceEnabled()) { + return; + } + this.lock.writeLock().lock(); try { - logger.trace("Activity: No. Gets: {}. No. Puts: {}. No. Gets from Store: {}", noGets, noPuts, noGetsFromStore); - - noGetsFromStore = 0; - noGets = 0; - noPuts = 0; + logger.trace("Activity: No. Gets: {}. No. Puts: {}. No. Gets from Store: {}", + noGets.getAndSet(0), + noPuts.getAndSet(0), + noGetsFromStore.getAndSet(0)); } finally { this.lock.writeLock().unlock(); diff --git a/rskj-core/src/test/java/co/rsk/cli/tools/CliToolsTest.java b/rskj-core/src/test/java/co/rsk/cli/tools/CliToolsTest.java index 8f0d9bd2cfe..94a05a5c047 100644 --- a/rskj-core/src/test/java/co/rsk/cli/tools/CliToolsTest.java +++ b/rskj-core/src/test/java/co/rsk/cli/tools/CliToolsTest.java @@ -160,7 +160,8 @@ public void executeBlocks() throws FileNotFoundException, DslProcessorException, String[] args = new String[] { "1", "2" }; - ExecuteBlocks.execute(args, world.getBlockExecutor(), world.getBlockStore(), world.getTrieStore()); + ExecuteBlocks.execute(args, world.getBlockExecutor(), world.getBlockStore(), world.getTrieStore(), + world.getStateRootHandler()); Assert.assertEquals(2, world.getBlockChain().getBestBlock().getNumber()); } From 8a30ee76e50abad122ea69a35106c87ca66feb97 Mon Sep 17 00:00:00 2001 From: Volodymyr Kravets Date: Fri, 2 Jul 2021 16:44:06 +0300 Subject: [PATCH 7/8] Changed prefix of trace fields --- .../main/java/co/rsk/trie/TrieStoreImpl.java | 44 +++++++++---------- .../datasource/DataSourceWithCache.java | 18 ++++---- 2 files changed, 31 insertions(+), 31 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index 42a5070f646..e3a75c9c1e7 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -55,9 +55,9 @@ public void save(Trie trie) { TraceInfo traceInfo = null; if (logger.isTraceEnabled()) { traceInfo = traceInfoLocal.get(); - traceInfo.noRetrievesInSaveTrie = 0; - traceInfo.noSavesInSaveTrie = 0; - traceInfo.noNoSavesInSaveTrie = 0; + traceInfo.numOfRetrievesInSaveTrie = 0; + traceInfo.numOfSavesInSaveTrie = 0; + traceInfo.numOfNoSavesInSaveTrie = 0; logger.trace("Start saving trie root."); } @@ -67,13 +67,13 @@ public void save(Trie trie) { if (traceInfo != null) { logger.trace("End saving trie root. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", - traceInfo.noRetrievesInSaveTrie, traceInfo.noSavesInSaveTrie, traceInfo.noNoSavesInSaveTrie); + traceInfo.numOfRetrievesInSaveTrie, traceInfo.numOfSavesInSaveTrie, traceInfo.numOfNoSavesInSaveTrie); logger.trace("End process block. No. Retrieves: {}. No. Saves: {}. No. No Saves: {}", - traceInfo.noRetrievesInBlockProcess, traceInfo.noSavesInBlockProcess, traceInfo.noNoSavesInBlockProcess); + traceInfo.numOfRetrievesInBlockProcess, traceInfo.numOfSavesInBlockProcess, traceInfo.numOfNoSavesInBlockProcess); - traceInfo.noRetrievesInBlockProcess = 0; - traceInfo.noSavesInBlockProcess = 0; - traceInfo.noNoSavesInBlockProcess = 0; + traceInfo.numOfRetrievesInBlockProcess = 0; + traceInfo.numOfSavesInBlockProcess = 0; + traceInfo.numOfNoSavesInBlockProcess = 0; if (store instanceof DataSourceWithCache) { ((DataSourceWithCache) store).emitLogs(); @@ -98,16 +98,16 @@ private void save(Trie trie, boolean isRootNode, int level, @Nullable TraceInfo logger.trace("End saving trie, level : {}, already saved.", level); if (traceInfo != null) { - traceInfo.noNoSavesInSaveTrie++; - traceInfo.noNoSavesInBlockProcess++; + traceInfo.numOfNoSavesInSaveTrie++; + traceInfo.numOfNoSavesInBlockProcess++; } return; } if (traceInfo != null) { - traceInfo.noSavesInSaveTrie++; - traceInfo.noSavesInBlockProcess++; + traceInfo.numOfSavesInSaveTrie++; + traceInfo.numOfSavesInBlockProcess++; } NodeReference leftNodeReference = trie.getLeft(); @@ -166,8 +166,8 @@ public Optional retrieve(byte[] hash) { if (logger.isTraceEnabled()) { TraceInfo traceInfo = traceInfoLocal.get(); - traceInfo.noRetrievesInSaveTrie++; - traceInfo.noRetrievesInBlockProcess++; + traceInfo.numOfRetrievesInSaveTrie++; + traceInfo.numOfRetrievesInBlockProcess++; } Trie trie = Trie.fromMessage(message, this).markAsSaved(); @@ -178,8 +178,8 @@ public Optional retrieve(byte[] hash) { public byte[] retrieveValue(byte[] hash) { if (logger.isTraceEnabled()) { TraceInfo traceInfo = traceInfoLocal.get(); - traceInfo.noRetrievesInSaveTrie++; - traceInfo.noRetrievesInBlockProcess++; + traceInfo.numOfRetrievesInSaveTrie++; + traceInfo.numOfRetrievesInBlockProcess++; } return this.store.get(hash); @@ -195,12 +195,12 @@ public void dispose() { * Should not be used when logger tracing is disabled ({@link Logger#isTraceEnabled()} is {@code false}). */ private static final class TraceInfo { - int noRetrievesInBlockProcess; - int noSavesInBlockProcess; - int noNoSavesInBlockProcess; + int numOfRetrievesInBlockProcess; + int numOfSavesInBlockProcess; + int numOfNoSavesInBlockProcess; - int noRetrievesInSaveTrie; - int noSavesInSaveTrie; - int noNoSavesInSaveTrie; + int numOfRetrievesInSaveTrie; + int numOfSavesInSaveTrie; + int numOfNoSavesInSaveTrie; } } diff --git a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java index b65dc2c6697..2861f835bcc 100644 --- a/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java +++ b/rskj-core/src/main/java/org/ethereum/datasource/DataSourceWithCache.java @@ -41,9 +41,9 @@ public class DataSourceWithCache implements KeyValueDataSource { private final ReentrantReadWriteLock lock = new ReentrantReadWriteLock(); - private final AtomicInteger noPuts = new AtomicInteger(); - private final AtomicInteger noGets = new AtomicInteger(); - private final AtomicInteger noGetsFromStore = new AtomicInteger(); + private final AtomicInteger numOfPuts = new AtomicInteger(); + private final AtomicInteger numOfGets = new AtomicInteger(); + private final AtomicInteger numOfGetsFromStore = new AtomicInteger(); public DataSourceWithCache(KeyValueDataSource base, int cacheSize) { this.cacheSize = cacheSize; @@ -74,7 +74,7 @@ public byte[] get(byte[] key) { value = base.get(key); if (traceEnabled) { - noGetsFromStore.incrementAndGet(); + numOfGetsFromStore.incrementAndGet(); } //null value, as expected, is allowed here to be stored in committedCache @@ -82,7 +82,7 @@ public byte[] get(byte[] key) { } finally { if (traceEnabled) { - noGets.incrementAndGet(); + numOfGets.incrementAndGet(); } this.lock.readLock().unlock(); @@ -116,7 +116,7 @@ private byte[] put(ByteArrayWrapper wrappedKey, byte[] value) { } finally { if (logger.isTraceEnabled()) { - noPuts.incrementAndGet(); + numOfPuts.incrementAndGet(); } this.lock.writeLock().unlock(); @@ -283,9 +283,9 @@ public void emitLogs() { try { logger.trace("Activity: No. Gets: {}. No. Puts: {}. No. Gets from Store: {}", - noGets.getAndSet(0), - noPuts.getAndSet(0), - noGetsFromStore.getAndSet(0)); + numOfGets.getAndSet(0), + numOfPuts.getAndSet(0), + numOfGetsFromStore.getAndSet(0)); } finally { this.lock.writeLock().unlock(); From 62edd7e19565df5e34fd073ffcdd464e1c70bfce Mon Sep 17 00:00:00 2001 From: Volodymyr Kravets Date: Mon, 6 Sep 2021 10:13:16 +0300 Subject: [PATCH 8/8] Fixed sonarcloud complaint --- .../src/main/java/co/rsk/trie/TrieStoreImpl.java | 14 ++++++++------ rskj-core/src/test/resources/logback.xml | 1 + 2 files changed, 9 insertions(+), 6 deletions(-) diff --git a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java index e3a75c9c1e7..2d7de5c1588 100644 --- a/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java +++ b/rskj-core/src/main/java/co/rsk/trie/TrieStoreImpl.java @@ -78,6 +78,8 @@ public void save(Trie trie) { if (store instanceof DataSourceWithCache) { ((DataSourceWithCache) store).emitLogs(); } + + traceInfoLocal.remove(); } } @@ -195,12 +197,12 @@ public void dispose() { * Should not be used when logger tracing is disabled ({@link Logger#isTraceEnabled()} is {@code false}). */ private static final class TraceInfo { - int numOfRetrievesInBlockProcess; - int numOfSavesInBlockProcess; - int numOfNoSavesInBlockProcess; + private int numOfRetrievesInBlockProcess; + private int numOfSavesInBlockProcess; + private int numOfNoSavesInBlockProcess; - int numOfRetrievesInSaveTrie; - int numOfSavesInSaveTrie; - int numOfNoSavesInSaveTrie; + private int numOfRetrievesInSaveTrie; + private int numOfSavesInSaveTrie; + private int numOfNoSavesInSaveTrie; } } diff --git a/rskj-core/src/test/resources/logback.xml b/rskj-core/src/test/resources/logback.xml index b92d6c2a72a..eb4b5dab233 100644 --- a/rskj-core/src/test/resources/logback.xml +++ b/rskj-core/src/test/resources/logback.xml @@ -70,6 +70,7 @@ +