From 3ffa7d9be9d93d9cbb3c0b2ccf0625974b4e0916 Mon Sep 17 00:00:00 2001 From: Marcos Date: Tue, 7 Feb 2023 14:52:31 -0300 Subject: [PATCH] Put method name in log messages in BtcToRskClient class --- .../java/co/rsk/federate/BtcToRskClient.java | 91 ++++++++++++------- 1 file changed, 60 insertions(+), 31 deletions(-) diff --git a/src/main/java/co/rsk/federate/BtcToRskClient.java b/src/main/java/co/rsk/federate/BtcToRskClient.java index 94cdf5aef..33ada9757 100644 --- a/src/main/java/co/rsk/federate/BtcToRskClient.java +++ b/src/main/java/co/rsk/federate/BtcToRskClient.java @@ -115,7 +115,7 @@ public synchronized void setup( } public void start(Federation federation) { - logger.info("Starting for Federation {}", federation.getAddress()); + logger.info("[start] Starting for Federation {}", federation.getAddress()); this.federation = federation; if (federation.isMember(federatorSupport.getFederationMember())) { logger.info("Watching federation {} since I belong to it", federation.getAddress().toString()); @@ -138,7 +138,7 @@ public void start(Federation federation) { } public void stop() { - logger.info("Stopping"); + logger.info("[stop] Stopping"); federation = null; @@ -178,7 +178,7 @@ public void updateBridge() { @Override public void onBlock(Block block) { synchronized (this) { - logger.debug("onBlock {}", block.getHash()); + logger.debug("[onBlock] onBlock {}", block.getHash()); PartialMerkleTree tree; Transaction coinbase = null; boolean dataToWrite = false; @@ -199,7 +199,7 @@ public void onBlock(Block block) { List proofs = fileData.getTransactionProofs().get(tx.getWTxId()); boolean blockInProofs = proofs.stream().anyMatch(p -> p.getBlockHash().equals(block.getHash())); if (blockInProofs) { - logger.info("Proof for tx {} in block {} already stored", tx, block.getHash()); + logger.info("[onBlock] Proof for tx {} in block {} already stored", tx, block.getHash()); continue; } @@ -221,14 +221,14 @@ public void onBlock(Block block) { // Validate information byte[] witnessReservedValue = coinbaseInformation.getCoinbaseWitnessReservedValue(); if (witnessReservedValue == null) { - logger.error("block {} with lock segwit tx {} has coinbase with no witness reserved value. Aborting block processing.", block.getHash(), tx.getWTxId()); + logger.error("[onBlock] block {} with lock segwit tx {} has coinbase with no witness reserved value. Aborting block processing.", block.getHash(), tx.getWTxId()); // Can't register this transaction, it would be rejected by the Bridge return; } Sha256Hash calculatedWitnessCommitment = Sha256Hash.twiceOf(witnessMerkleRoot.getReversedBytes(), witnessReservedValue); Sha256Hash witnessCommitment = coinbase.findWitnessCommitment(); if (!witnessCommitment.equals(calculatedWitnessCommitment)) { - logger.error("block {} with lock segwit tx {} generated an invalid witness merkle root", tx.getWTxId(), block.getHash()); + logger.error("[onBlock] block {} with lock segwit tx {} generated an invalid witness merkle root", tx.getWTxId(), block.getHash()); // Can't register this transaction, it would be rejected by the Bridge return; } @@ -238,14 +238,14 @@ public void onBlock(Block block) { // Register the coinbase just once per block coinbaseRegistered = true; } catch (Exception e) { - logger.error(e.getMessage(), e); + logger.error("[onBlock] {}", e.getMessage()); // Without a coinbase related to this transaction the Bridge would reject the transaction return; } } proofs.add(new Proof(block.getHash(), tree)); - logger.info("New proof for tx {} in block {}", tx, block.getHash()); + logger.info("[onBlock] New proof for tx {} in block {}", tx, block.getHash()); dataToWrite = true; } @@ -255,9 +255,9 @@ public void onBlock(Block block) { try { this.btcToRskClientFileStorage.write(fileData); - logger.info("Stored proofs for block {}", block.getHash()); + logger.info("[onBlock] Stored proofs for block {}", block.getHash()); } catch (IOException e) { - logger.error(e.getMessage(), e); + logger.error("[onBlock] {}", e.getMessage()); panicProcessor.panic("btclock", e.getMessage()); } } @@ -265,13 +265,13 @@ public void onBlock(Block block) { @Override public void onTransaction(Transaction tx) { - logger.debug("onTransaction {}", tx.getWTxId()); + logger.debug("[onTransaction] onTransaction {}", tx.getWTxId()); synchronized (this) { this.fileData.getTransactionProofs().put(tx.getWTxId(), new ArrayList<>()); try { this.btcToRskClientFileStorage.write(this.fileData); } catch (IOException e) { - logger.error(e.getMessage(), e); + logger.error("[onTransaction] {}", e.getMessage()); panicProcessor.panic("btclock", e.getMessage()); } } @@ -284,7 +284,11 @@ public int updateBridgeBtcBlockchain() throws BlockStoreException, IOException { int bridgeBtcBlockchainBestChainHeight = federatorSupport.getBtcBestBlockChainHeight(); int federatorBtcBlockchainBestChainHeight = bitcoinWrapper.getBestChainHeight(); if (federatorBtcBlockchainBestChainHeight > bridgeBtcBlockchainBestChainHeight) { - logger.debug("BTC blockchain height - Federator : {}, Bridge : {}.", bitcoinWrapper.getBestChainHeight(), bridgeBtcBlockchainBestChainHeight); + logger.debug( + "[updateBridgeBtcBlockchain] BTC blockchain height - Federator : {}, Bridge : {}", + federatorBtcBlockchainBestChainHeight, + bridgeBtcBlockchainBestChainHeight + ); // Federator's blockchain has more blocks than bridge's blockchain - go and try to // update the bridge with the latest. @@ -300,7 +304,7 @@ public int updateBridgeBtcBlockchain() throws BlockStoreException, IOException { checkNotNull(commonAncestor, "No best chain block found"); - logger.debug("Matched block {}.", commonAncestor.getHeader().getHash()); + logger.debug("[updateBridgeBtcBlockchain] Matched block {}.", commonAncestor.getHeader().getHash()); // We found a common ancestor. Send receiveHeaders with the blocks it is missing. StoredBlock current = bitcoinWrapper.getChainHead(); @@ -310,19 +314,29 @@ public int updateBridgeBtcBlockchain() throws BlockStoreException, IOException { current = bitcoinWrapper.getBlock(current.getHeader().getPrevBlockHash()); } if (headersToSendToBridge.isEmpty()) { - logger.debug("Bridge was just updated, no new blocks to send, matchedBlock: {}.", commonAncestor.getHeader().getHash()); + logger.debug( + "[updateBridgeBtcBlockchain] Bridge was just updated, no new blocks to send, matchedBlock: {}.", + commonAncestor.getHeader().getHash() + ); return 0; } headersToSendToBridge = Lists.reverse(headersToSendToBridge); - logger.debug("Headers missing in the bridge {}.", headersToSendToBridge.size()); + logger.debug( + "[updateBridgeBtcBlockchain] Headers missing in the bridge {}.", + headersToSendToBridge.size() + ); int to = Math.min(amountOfHeadersToSend, headersToSendToBridge.size()); List headersToSendToBridgeSubList = headersToSendToBridge.subList(0, to); federatorSupport.sendReceiveHeaders(headersToSendToBridgeSubList.toArray(new Block[]{})); this.markCoinbasesAsReadyToBeInformed(headersToSendToBridgeSubList); - logger.debug("Invoked receiveHeaders with {} blocks. First {}, Last {}.", headersToSendToBridgeSubList.size(), - headersToSendToBridgeSubList.get(0).getHash(), headersToSendToBridgeSubList.get(headersToSendToBridgeSubList.size()-1).getHash()); + logger.debug( + "[updateBridgeBtcBlockchain] Invoked receiveHeaders with {} blocks. First {}, Last {}.", + headersToSendToBridgeSubList.size(), + headersToSendToBridgeSubList.get(0).getHash(), + headersToSendToBridgeSubList.get(headersToSendToBridgeSubList.size()-1).getHash() + ); return headersToSendToBridgeSubList.size(); } @@ -407,7 +421,11 @@ private StoredBlock findBridgeBtcBlockchainMatchingAncestorUsingBlockLocator() t // Find the last best chain block the bridge has with respect // to the federate node's best chain. Object[] blockLocatorArray = federatorSupport.getBtcBlockchainBlockLocator(); - logger.debug("Block locator size {}, first {}, last {}.", blockLocatorArray.length, blockLocatorArray[0], blockLocatorArray[blockLocatorArray.length - 1]); + logger.debug( + "[findBridgeBtcBlockchainMatchingAncestorUsingBlockLocator] Block locator size {}, first {}, last {}.", + blockLocatorArray.length, blockLocatorArray[0], + blockLocatorArray[blockLocatorArray.length - 1] + ); StoredBlock matchedBlock = null; for (Object o : blockLocatorArray) { @@ -556,29 +574,40 @@ public void updateBridgeBtcTransactions() throws BlockStoreException { * Gets the first ready to be informed coinbase transaction and informs it */ public void updateBridgeBtcCoinbaseTransactions() { - Optional coinbaseInformationReadyToInform = fileData.getCoinbaseInformationMap().values().stream() - .filter(CoinbaseInformation::isReadyToInform).findFirst(); + Optional coinbaseInformationReadyToInform = fileData + .getCoinbaseInformationMap() + .values() + .stream() + .filter(CoinbaseInformation::isReadyToInform) + .findFirst(); if (!coinbaseInformationReadyToInform.isPresent()) { - logger.debug("no coinbase transaction to inform"); + logger.debug("[updateBridgeBtcCoinbaseTransactions] no coinbase transaction to inform"); return; } CoinbaseInformation coinbaseInformation = coinbaseInformationReadyToInform.get(); - logger.debug("coinbase transaction {} ready to be informed for block {}", coinbaseInformation.getCoinbaseTransaction().getTxId(), coinbaseInformation.getBlockHash()); + logger.debug( + "[updateBridgeBtcCoinbaseTransactions] coinbase transaction {} ready to be informed for block {}", + coinbaseInformation.getCoinbaseTransaction().getTxId(), + coinbaseInformation.getBlockHash() + ); long bestBlockNumber = federatorSupport.getRskBestChainHeight(); if (activationConfig.isActive(ConsensusRule.RSKIP143, bestBlockNumber)) { if (!federatorSupport.hasBlockCoinbaseInformed(coinbaseInformation.getBlockHash())) { - logger.debug("informing coinbase transaction {}", coinbaseInformation.getCoinbaseTransaction().getTxId()); + logger.debug( + "[updateBridgeBtcCoinbaseTransactions] informing coinbase transaction {}", + coinbaseInformation.getCoinbaseTransaction().getTxId() + ); federatorSupport.sendRegisterCoinbaseTransaction(coinbaseInformation); } else { - logger.debug("coinbase transaction already informed, removing from map"); + logger.debug("[updateBridgeBtcCoinbaseTransactions] coinbase transaction already informed, removing from map"); // Remove the coinbase from the map fileData.getCoinbaseInformationMap().remove(coinbaseInformation.getBlockHash()); } } else { - logger.debug("RSKIP-143 is not active. Can't send coinbase transactions."); + logger.debug("[updateBridgeBtcCoinbaseTransactions] RSKIP-143 is not active. Can't send coinbase transactions."); // Remove the coinbase from the map fileData.getCoinbaseInformationMap().remove(coinbaseInformation.getBlockHash()); } @@ -617,7 +646,7 @@ private StoredBlock findBestChainStoredBlockFor(Transaction tx) throws IllegalSt @PreDestroy public void tearDown() throws IOException { - logger.info("BtcToRskClient tearDown starting..."); + logger.info("[tearDown] BtcToRskClient tearDown starting..."); if (federation != null) { bitcoinWrapper.removeFederationListener(federation, this); @@ -629,7 +658,7 @@ public void tearDown() throws IOException { this.btcToRskClientFileStorage.write(this.fileData); } - logger.info("BtcToRskClient tearDown finished."); + logger.info("[tearDown] BtcToRskClient tearDown finished."); } private void restoreFileData() throws Exception { @@ -641,12 +670,12 @@ private void restoreFileData() throws Exception { this.fileData = result.getData(); } else { String errorMessage = "Can't operate without a valid storage file"; - logger.error(errorMessage); - panicProcessor.panic("fed-storage",errorMessage); + logger.error("[restoreFileData] {}", errorMessage); + panicProcessor.panic("fed-storage", errorMessage); throw new Exception(errorMessage); } } catch (IOException e) { - logger.error("Failed to read data from BtcToRskClient file: {}", e.getMessage(), e); + logger.error("[restoreFileData] Failed to read data from BtcToRskClient file: {}", e.getMessage(), e); panicProcessor.panic("fed-storage",e.getMessage()); throw new Exception("Failed to read data from BtcToRskClient file", e); }