Uploaded image for project: 'Corda'
  1. CORDA-2572

Errors received from peers can't be distinguished from local errors

    Details

    • Type: Bug
    • Status: Done (View workflow)
    • Priority: Medium
    • Resolution: Done
    • Affects versions: None
    • Fix versions: Corda 4.1
    • Components: None
    • Labels:
      None
    • Severity:
      Medium
    • Target Version/s:
    • Feature Team:
      Corda Core
    • Sprint:
      Corda Core Sprint 1, Corda Core Sprint 2

      Description

      Below is the error message on the receiving node when the sender of the CashPayment has insufficient funds.

      The error message is really confusing.

      Note that the receiving node has already entered the finality flow, a bug that Tudor Malene is tackling at the moment.

      [INFO ] 2019-02-11T16:00:12,671Z [Node thread-1] statemachine.StaffedFlowHospital.invoke - Flow [7011f9c9-4a79-473e-b405-7cf11b6fb1f4] has error [0] {fiber-id=10000003, flow-id=7011f9c9-4a79-473e-b405-7cf11b6fb1f4, invocation_id=8a058c6f-89db-4799-a8a4-45600e08ea37, invocation_timestamp=2019-02-11T16:00:04.179Z, origin=O=Bob, L=London, C=GB, session_id=8a058c6f-89db-4799-a8a4-45600e08ea37, session_timestamp=2019-02-11T16:00:04.179Z, thread-id=140}
      net.corda.finance.flows.CashException: Insufficient cash for spend: Insufficient balance, missing 50.00 CHF
              at net.corda.node.services.statemachine.FlowStateMachineImpl.processEventsUntilFlowIsResumed(FlowStateMachineImpl.kt:161) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowStateMachineImpl.suspend(FlowStateMachineImpl.kt:407) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowSessionImpl.receive(FlowSessionImpl.kt:67) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowSessionImpl.receive(FlowSessionImpl.kt:71) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.core.flows.ReceiveTransactionFlow.call(ReceiveTransactionFlow.kt:99) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.core.flows.ReceiveTransactionFlow.call(ReceiveTransactionFlow.kt:27) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowStateMachineImpl.subFlow(FlowStateMachineImpl.kt:290) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.core.flows.FlowLogic.subFlow(FlowLogic.kt:311) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.core.flows.ReceiveFinalityFlow.call(FinalityFlow.kt:260) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.core.flows.ReceiveFinalityFlow.call(FinalityFlow.kt:255) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowStateMachineImpl.subFlow(FlowStateMachineImpl.kt:290) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.core.flows.FlowLogic.subFlow(FlowLogic.kt:311) ~[corda-core-4.0-RC04.jar:?]
              at net.corda.finance.flows.CashPaymentReceiverFlow.call(CashPaymentFlow.kt:106) ~[?:?]
              at net.corda.finance.flows.CashPaymentReceiverFlow.call(CashPaymentFlow.kt:97) ~[?:?]
              at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:228) ~[corda-node-4.0-RC04.jar:?]
              at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:45) ~[corda-node-4.0-RC04.jar:?]
              at co.paralleluniverse.fibers.Fiber.run1(Fiber.java:1092) ~[quasar-core-0.7.10-jdk8.jar:0.7.10]
              at co.paralleluniverse.fibers.Fiber.exec(Fiber.java:788) ~[quasar-core-0.7.10-jdk8.jar:0.7.10]
              at co.paralleluniverse.fibers.RunnableFiberTask.doExec(RunnableFiberTask.java:100) ~[quasar-core-0.7.10-jdk8.jar:0.7.10]
              at co.paralleluniverse.fibers.RunnableFiberTask.run(RunnableFiberTask.java:91) ~[quasar-core-0.7.10-jdk8.jar:0.7.10]
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172]
              at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_172]
              at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_172]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_172]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_172]
              at net.corda.node.utilities.AffinityExecutor$ServiceAffinityExecutor$1$thread$1.run(AffinityExecutor.kt:63) ~[corda-node-4.0-RC04.jar:?]
      Caused by: net.corda.core.contracts.InsufficientBalanceException: Insufficient balance, missing 50.00 CHF
      [WARN ] 2019-02-11T16:00:12,671Z [Node thread-1] statemachine.StaffedFlowHospital.consult - Flow [7011f9c9-4a79-473e-b405-7cf11b6fb1f4] failed to be finalised. Manual intervention may be required before retrying the flow by re-starting the node. State machine state: StateMachineState(checkpoint=Checkpoint(invocationContext=InvocationContext(origin=Peer(party=O=Bob, L=London, C=GB), trace=Trace(invocationId=8a058c6f-89db-4799-a8a4-45600e08ea37, timestamp: 2019-02-11T16:00:04.179Z, entityType: Invocation, sessionId=8a058c6f-89db-4799-a8a4-45600e08ea37, timestamp: 2019-02-11T16:00:04.179Z, entityType: Session), actor=null, externalTrace=null, impersonatedActor=null), ourIdentity=O=Carol, L=London, C=GB, sessions={SessionId(toLong=8433019307067059943)=Initiated(peerParty=O=Bob, L=London, C=GB, peerFlowInfo=FlowInfo(flowVersion=1, appName=corda-finance-workflows-4.0-RC02), receivedMessages=[], initiatedState=Live(peerSinkSessionId=SessionId(toLong=6932833200206345579)), errors=[FlowError(errorId=-4253397971800966829, exception=net.corda.finance.flows.CashException: Insufficient cash for spend: Insufficient balance, missing 50.00 CHF)], deduplicationSeed=D-6932833200206345579-6735409289698902659)}, subFlowStack=[Inlined(flowClass=class net.corda.finance.flows.CashPaymentReceiverFlow, subFlowVersion=CorDappFlow(platformVersion=4, corDappName=corda-finance-workflows-4.0-RC02, corDappHash=0C546C8BB9A9A661A5260F5EE68E4A8F67EC56B87D41EE706D49554E78F29B40), isEnabledTimedFlow=false)], flowState=Started(flowIORequest=Receive(sessions=[FlowSessionImpl(counterparty=O=Bob, L=London, C=GB, sourceSessionId=SessionId(toLong=8433019307067059943))]), frozenFiber=957B171E516581CD012C376F6A593DD67C59D310F3A686652F972E7C47B717F5), errorState=Clean, numberOfSuspends=2), flowLogic=net.corda.finance.flows.CashPaymentReceiverFlow@22246648, pendingDeduplicationHandlers=[MessageDeduplicationHandler(DeduplicationId(toString=E--4253397971800966829-8433019307067059943))], isFlowResumed=true, isTransactionTracked=false, isAnyCheckpointPersisted=true, isStartIdempotent=false, isRemoved=false, senderUUID=9dce4010-459d-4389-a4ab-c7bff7a602cc) {fiber-id=10000003, flow-id=7011f9c9-4a79-473e-b405-7cf11b6fb1f4, invocation_id=8a058c6f-89db-4799-a8a4-45600e08ea37, invocation_timestamp=2019-02-11T16:00:04.179Z, origin=O=Bob, L=London, C=GB, session_id=8a058c6f-89db-4799-a8a4-45600e08ea37, session_timestamp=2019-02-11T16:00:04.179Z, thread-id=140}
      [INFO ] 2019-02-11T16:00:12,671Z [Node thread-1] statemachine.StaffedFlowHospital.flowErrored - Flow [7011f9c9-4a79-473e-b405-7cf11b6fb1f4] error kept for overnight observation by [net.corda.node.services.statemachine.StaffedFlowHospital$FinalityDoctor@7dbf4f57] {fiber-id=10000003, flow-id=7011f9c9-4a79-473e-b405-7cf11b6fb1f4, invocation_id=8a058c6f-89db-4799-a8a4-45600e08ea37, invocation_timestamp=2019-02-11T16:00:04.179Z, origin=O=Bob, L=London, C=GB, session_id=8a058c6f-89db-4799-a8a4-45600e08ea37, session_timestamp=2019-02-11T16:00:04.179Z, thread-id=140}
      [INFO ] 2019-02-11T16:00:40,375Z [pool-10-thread-1] statemachine.FlowMonitor.logFlowsWaitingForParty - Flow with id d25ba994-6a31-479f-af89-8d7a590c6e54 has been waiting for 719 seconds to receive messages from parties [O=Bob, L=London, C=GB].
      [INFO ] 2019-02-11T16:01:40,375Z [pool-10-thread-1] statemachine.FlowMonitor.logFlowsWaitingForParty - Flow with id d25ba994-6a31-479f-af89-8d7a590c6e54 has been waiting for 779 seconds to receive messages from parties [O=Bob, L=London, C=GB].
      

        Attachments

          Activity

            People

            • Assignee:
              dan.newton Dan Newton
              Reporter:
              Thomas.Schroeter Thomas Schroeter
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: