From d4b982b9fb65a7fe901a26c652a26da84d504723 Mon Sep 17 00:00:00 2001
From: Viktor Kolomeyko <viktor.kolomeyko@r3.com>
Date: Tue, 19 Jun 2018 15:29:35 +0100
Subject: [PATCH] ENT-2054: Logging improvements (#3397)

---
 core/src/main/kotlin/net/corda/core/flows/NotaryError.kt    | 6 ++++--
 .../core/serialization/NotaryExceptionSerializationTest.kt  | 2 ++
 .../main/kotlin/net/corda/finance/flows/CashPaymentFlow.kt  | 4 ++++
 3 files changed, 10 insertions(+), 2 deletions(-)

diff --git a/core/src/main/kotlin/net/corda/core/flows/NotaryError.kt b/core/src/main/kotlin/net/corda/core/flows/NotaryError.kt
index 281f3dfff6..4b082ad10f 100644
--- a/core/src/main/kotlin/net/corda/core/flows/NotaryError.kt
+++ b/core/src/main/kotlin/net/corda/core/flows/NotaryError.kt
@@ -15,7 +15,7 @@ class NotaryException(
         val error: NotaryError,
         /** Id of the transaction to be notarised. Can be _null_ if an error occurred before the id could be resolved. */
         val txId: SecureHash? = null
-) : FlowException("Unable to notarise transaction${txId ?: " "}: $error")
+) : FlowException("Unable to notarise transaction ${txId ?: "<Unknown>"} : $error")
 
 /** Specifies the cause for notarisation request failure. */
 @CordaSerializable
@@ -27,7 +27,9 @@ sealed class NotaryError {
             /** Specifies which states have already been consumed in another transaction. */
             val consumedStates: Map<StateRef, StateConsumptionDetails>
     ) : NotaryError() {
-        override fun toString() = "One or more input states have been used in another transaction"
+        override fun toString() = "Conflict notarising transaction $txId. " +
+                "Input states have been used in another transactions, count: ${consumedStates.size}, " +
+                "content: ${consumedStates.asSequence().joinToString(limit = 5) { it.key.toString() + "->" + it.value }}"
     }
 
     /** Occurs when time specified in the [TimeWindow] command is outside the allowed tolerance. */
diff --git a/core/src/test/kotlin/net/corda/core/serialization/NotaryExceptionSerializationTest.kt b/core/src/test/kotlin/net/corda/core/serialization/NotaryExceptionSerializationTest.kt
index b1cd4e7d4f..c0a9a642f6 100644
--- a/core/src/test/kotlin/net/corda/core/serialization/NotaryExceptionSerializationTest.kt
+++ b/core/src/test/kotlin/net/corda/core/serialization/NotaryExceptionSerializationTest.kt
@@ -10,6 +10,7 @@ import net.corda.testing.core.SerializationEnvironmentRule
 import org.junit.Rule
 import org.junit.Test
 import kotlin.test.assertEquals
+import kotlin.test.assertTrue
 
 class NotaryExceptionSerializationTest {
     @Rule
@@ -27,5 +28,6 @@ class NotaryExceptionSerializationTest {
         val instanceOnTheOtherSide = instance.serialize().bytes.deserialize<NotaryException>()
 
         assertEquals(instance.error, instanceOnTheOtherSide.error)
+        assertTrue(instance.error.toString().contains("->"))
     }
 }
\ No newline at end of file
diff --git a/finance/src/main/kotlin/net/corda/finance/flows/CashPaymentFlow.kt b/finance/src/main/kotlin/net/corda/finance/flows/CashPaymentFlow.kt
index f3afc3a107..b45d61067b 100644
--- a/finance/src/main/kotlin/net/corda/finance/flows/CashPaymentFlow.kt
+++ b/finance/src/main/kotlin/net/corda/finance/flows/CashPaymentFlow.kt
@@ -52,6 +52,7 @@ open class CashPaymentFlow(
         val anonymousRecipient = txIdentities[recipient] ?: recipient
         progressTracker.currentStep = GENERATING_TX
         val builder = TransactionBuilder(notary = null)
+        logger.info("Generating spend for: ${builder.lockId}")
         // TODO: Have some way of restricting this to states the caller controls
         val (spendTX, keysForSigning) = try {
             Cash.generateSpend(serviceHub,
@@ -65,10 +66,13 @@ open class CashPaymentFlow(
         }
 
         progressTracker.currentStep = SIGNING_TX
+        logger.info("Signing transaction for: ${spendTX.lockId}")
         val tx = serviceHub.signInitialTransaction(spendTX, keysForSigning)
 
         progressTracker.currentStep = FINALISING_TX
+        logger.info("Finalising transaction for: ${tx.id}")
         val notarised = finaliseTx(tx, setOf(recipient), "Unable to notarise spend")
+        logger.info("Finalised transaction for: ${notarised.id}")
         return Result(notarised, anonymousRecipient)
     }