From d1e147b1c13cc0fe488441c125d791a072062769 Mon Sep 17 00:00:00 2001 From: Michele Sollecito Date: Thu, 24 May 2018 16:06:14 +0100 Subject: [PATCH] [CORDA-1638]: Audit log of failed transactions MVP. (#3231) --- .../net/corda/core/flows/FinalityFlow.kt | 21 ++++++++--- .../kotlin/net/corda/core/flows/NotaryFlow.kt | 4 ++ .../core/flows/ReceiveTransactionFlow.kt | 18 ++++++--- .../net/corda/core/internal/InternalUtils.kt | 37 +++++++++++++++++-- docs/source/changelog.rst | 2 + 5 files changed, 68 insertions(+), 14 deletions(-) diff --git a/core/src/main/kotlin/net/corda/core/flows/FinalityFlow.kt b/core/src/main/kotlin/net/corda/core/flows/FinalityFlow.kt index a958ef6a91..3e16992191 100644 --- a/core/src/main/kotlin/net/corda/core/flows/FinalityFlow.kt +++ b/core/src/main/kotlin/net/corda/core/flows/FinalityFlow.kt @@ -4,6 +4,7 @@ import co.paralleluniverse.fibers.Suspendable import net.corda.core.crypto.isFulfilledBy import net.corda.core.identity.Party import net.corda.core.identity.groupAbstractPartyByWellKnownParty +import net.corda.core.internal.pushToLoggingContext import net.corda.core.transactions.LedgerTransaction import net.corda.core.transactions.SignedTransaction import net.corda.core.utilities.ProgressTracker @@ -51,17 +52,24 @@ class FinalityFlow(val transaction: SignedTransaction, // // Lookup the resolved transactions and use them to map each signed transaction to the list of participants. // Then send to the notary if needed, record locally and distribute. + + transaction.pushToLoggingContext() + val commandDataTypes = transaction.tx.commands.map { it.value }.mapNotNull { it::class.qualifiedName }.distinct() + logger.info("Started finalization, commands are ${commandDataTypes.joinToString(", ", "[", "]")}.") val parties = getPartiesToSend(verifyTx()) val notarised = notariseAndRecord() // Each transaction has its own set of recipients, but extra recipients get them all. progressTracker.currentStep = BROADCASTING - for (party in parties) { - if (!serviceHub.myInfo.isLegalIdentity(party)) { - val session = initiateFlow(party) - subFlow(SendTransactionFlow(session, notarised)) - } + val recipients = parties.filterNot(serviceHub.myInfo::isLegalIdentity) + logger.info("Broadcasting transaction to parties ${recipients.map { it.name }.joinToString(", ", "[", "]")}.") + for (party in recipients) { + logger.info("Sending transaction to party ${party.name}.") + val session = initiateFlow(party) + subFlow(SendTransactionFlow(session, notarised)) + logger.info("Party ${party.name} received the transaction.") } + logger.info("All parties received the transaction successfully.") return notarised } @@ -73,9 +81,12 @@ class FinalityFlow(val transaction: SignedTransaction, val notarySignatures = subFlow(NotaryFlow.Client(transaction)) transaction + notarySignatures } else { + logger.info("No need to notarise this transaction.") transaction } + logger.info("Recording transaction locally.") serviceHub.recordTransactions(notarised) + logger.info("Recorded transaction locally successfully.") return notarised } diff --git a/core/src/main/kotlin/net/corda/core/flows/NotaryFlow.kt b/core/src/main/kotlin/net/corda/core/flows/NotaryFlow.kt index b4a4f874ec..bfe80e7c7e 100644 --- a/core/src/main/kotlin/net/corda/core/flows/NotaryFlow.kt +++ b/core/src/main/kotlin/net/corda/core/flows/NotaryFlow.kt @@ -9,6 +9,7 @@ import net.corda.core.identity.Party import net.corda.core.internal.FetchDataFlow import net.corda.core.internal.notary.generateSignature import net.corda.core.internal.notary.validateSignatures +import net.corda.core.internal.pushToLoggingContext import net.corda.core.transactions.ContractUpgradeWireTransaction import net.corda.core.transactions.SignedTransaction import net.corda.core.transactions.WireTransaction @@ -44,9 +45,12 @@ class NotaryFlow { @Suspendable @Throws(NotaryException::class) override fun call(): List { + stx.pushToLoggingContext() val notaryParty = checkTransaction() progressTracker.currentStep = REQUESTING + logger.info("Sending transaction to notary: ${notaryParty.name}.") val response = notarise(notaryParty) + logger.info("Notary responded.") progressTracker.currentStep = VALIDATING return validateResponse(response, notaryParty) } diff --git a/core/src/main/kotlin/net/corda/core/flows/ReceiveTransactionFlow.kt b/core/src/main/kotlin/net/corda/core/flows/ReceiveTransactionFlow.kt index 76dc39dba7..66f17daccb 100644 --- a/core/src/main/kotlin/net/corda/core/flows/ReceiveTransactionFlow.kt +++ b/core/src/main/kotlin/net/corda/core/flows/ReceiveTransactionFlow.kt @@ -3,6 +3,7 @@ package net.corda.core.flows import co.paralleluniverse.fibers.Suspendable import net.corda.core.contracts.* import net.corda.core.internal.ResolveTransactionsFlow +import net.corda.core.internal.pushToLoggingContext import net.corda.core.node.StatesToRecord import net.corda.core.transactions.SignedTransaction import net.corda.core.utilities.unwrap @@ -36,18 +37,25 @@ class ReceiveTransactionFlow @JvmOverloads constructor(private val otherSideSess } else { logger.trace("Receiving a transaction (but without checking the signatures) from ${otherSideSession.counterparty}") } - val stx = otherSideSession.receive().unwrap { + it.pushToLoggingContext() + logger.info("Received transaction acknowledgement request from party ${otherSideSession.counterparty.name}.") subFlow(ResolveTransactionsFlow(it, otherSideSession)) - it.verify(serviceHub, checkSufficientSignatures) - it + logger.info("Transaction dependencies resolution completed.") + try { + it.verify(serviceHub, checkSufficientSignatures) + it + } catch (e: Exception) { + logger.warn("Transaction verification failed.") + throw e + } } - if (checkSufficientSignatures) { // We should only send a transaction to the vault for processing if we did in fact fully verify it, and // there are no missing signatures. We don't want partly signed stuff in the vault. - logger.trace("Successfully received fully signed tx ${stx.id}, sending to the vault for processing") + logger.info("Successfully received fully signed tx. Sending it to the vault for processing.") serviceHub.recordTransactions(statesToRecord, setOf(stx)) + logger.info("Successfully recorded received transaction locally.") } return stx } diff --git a/core/src/main/kotlin/net/corda/core/internal/InternalUtils.kt b/core/src/main/kotlin/net/corda/core/internal/InternalUtils.kt index c8059035da..5f4472b884 100644 --- a/core/src/main/kotlin/net/corda/core/internal/InternalUtils.kt +++ b/core/src/main/kotlin/net/corda/core/internal/InternalUtils.kt @@ -7,13 +7,19 @@ import com.google.common.hash.HashingInputStream import net.corda.core.cordapp.Cordapp import net.corda.core.cordapp.CordappConfig import net.corda.core.cordapp.CordappContext -import net.corda.core.crypto.* +import net.corda.core.crypto.Crypto +import net.corda.core.crypto.DigitalSignature +import net.corda.core.crypto.SecureHash +import net.corda.core.crypto.SignedData +import net.corda.core.crypto.sha256 +import net.corda.core.crypto.sign import net.corda.core.identity.CordaX500Name import net.corda.core.node.ServicesForResolution import net.corda.core.serialization.SerializationContext import net.corda.core.serialization.SerializedBytes import net.corda.core.serialization.deserialize import net.corda.core.serialization.serialize +import net.corda.core.transactions.SignedTransaction import net.corda.core.transactions.TransactionBuilder import net.corda.core.transactions.WireTransaction import net.corda.core.utilities.OpaqueBytes @@ -21,11 +27,15 @@ import org.bouncycastle.asn1.x500.X500Name import org.bouncycastle.asn1.x500.X500NameBuilder import org.bouncycastle.asn1.x500.style.BCStyle import org.slf4j.Logger +import org.slf4j.MDC import rx.Observable import rx.Observer import rx.subjects.PublishSubject import rx.subjects.UnicastSubject -import java.io.* +import java.io.ByteArrayOutputStream +import java.io.IOException +import java.io.InputStream +import java.io.OutputStream import java.lang.reflect.Field import java.lang.reflect.Modifier import java.math.BigDecimal @@ -41,11 +51,23 @@ import java.nio.file.Paths import java.security.KeyPair import java.security.PrivateKey import java.security.PublicKey -import java.security.cert.* +import java.security.cert.CertPath +import java.security.cert.CertPathValidator +import java.security.cert.CertPathValidatorException +import java.security.cert.PKIXCertPathValidatorResult +import java.security.cert.PKIXParameters +import java.security.cert.TrustAnchor +import java.security.cert.X509Certificate import java.time.Duration import java.time.temporal.Temporal import java.util.* -import java.util.Spliterator.* +import java.util.Spliterator.DISTINCT +import java.util.Spliterator.IMMUTABLE +import java.util.Spliterator.NONNULL +import java.util.Spliterator.ORDERED +import java.util.Spliterator.SIZED +import java.util.Spliterator.SORTED +import java.util.Spliterator.SUBSIZED import java.util.concurrent.ExecutorService import java.util.concurrent.TimeUnit import java.util.stream.IntStream @@ -459,3 +481,10 @@ val PublicKey.hash: SecureHash get() = encoded.sha256() * Extension method for providing a sumBy method that processes and returns a Long */ fun Iterable.sumByLong(selector: (T) -> Long): Long = this.map { selector(it) }.sum() + +/** + * Ensures each log entry from the current thread will contain id of the transaction in the MDC. + */ +internal fun SignedTransaction.pushToLoggingContext() { + MDC.put("tx_id", id.toString()) +} \ No newline at end of file diff --git a/docs/source/changelog.rst b/docs/source/changelog.rst index 3c5b6a4a19..b79be24fa3 100644 --- a/docs/source/changelog.rst +++ b/docs/source/changelog.rst @@ -7,6 +7,8 @@ release, see :doc:`upgrade-notes`. Unreleased ========== +* Improved audit trail for ``FinalityFlow`` and related sub-flows. + * ``NodeStartup`` will now only print node's configuration if ``devMode`` is ``true``, avoiding the risk of printing passwords in a production setup. * SLF4J's MDC will now only be printed to the console if not empty. No more log lines ending with "{}".