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

Progress tracker not reloadable in checkpoints written in Java

    Details

    • Type: Bug
    • Status: Done (View workflow)
    • Priority: Highest
    • Resolution: Done
    • Affects versions: None
    • Fix versions: Corda 4.1
    • Components: None
    • Labels:
      None

      Description

      Can be replicated using the test on this PR: https://github.com/corda/corda/pull/4933
      The test might need to be run a couple of times, as the node needs to be killed at just the right moment

      The log of the test:

       [INFO] 13:42:06,041 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.invoke - Added(stateMachineInfo=StateMachineInfo([94b42d2e-b2d7-408c-b3f5-f970ad502ee7], net.corda.finance.flows.CashIssueAndPaymentFlow))
          [INFO] 13:42:06,042 [Test worker] rpc.RpcReconnectTests.invoke - Started flow 62 with flowId: [94b42d2e-b2d7-408c-b3f5-f970ad502ee7]
          [INFO] 13:42:06,042 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.call - Progress [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] : Starting
          [INFO] 13:42:06,042 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.call - Progress [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] : Issuing cash
          [INFO] 13:42:06,042 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.call - Progress [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] : Generating transaction
          [INFO] 13:42:06,042 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.call - Progress [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] : Signing transaction
          [INFO] 13:42:06,054 [rpc-client-observation-pool-0] rpc.RpcReconnectTests.call - Progress [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] : Finalising transaction
          [INFO] 13:42:27,891 [rpc-client-observation-pool-1] rpc.RpcReconnectTests.invoke - Added(stateMachineInfo=StateMachineInfo([94b42d2e-b2d7-408c-b3f5-f970ad502ee7], net.corda.finance.flows.CashIssueAndPaymentFlow))
          [INFO] 13:42:28,168 [rpc-client-observation-pool-1] rpc.RpcReconnectTests.invoke - Removed(id=[94b42d2e-b2d7-408c-b3f5-f970ad502ee7], result=Failure(net.corda.core.CordaRuntimeException: java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.))
      

      The log of the node:

      java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.
          at net.corda.core.utilities.ProgressTracker.setCurrentStep(ProgressTracker.kt:114) ~[corda-core-5.0-SNAPSHOT.jar:?]
          at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:49) ~[?:?]
          at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:26) ~[?:?]
          at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:239) ~[corda-node-5.0-SNAPSHOT.jar:?]
      

      Basically when the node is killed after the Issue subflow succeeded, the Payment subflow fails with that ProgressTracker error that prevents it from finishing.

      More log:

      [INFO ] 2019-04-03T12:42:27,913Z [Node thread-1] corda.flow.run - Flow raised an error... sending it to flow hospital {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.
      	at net.corda.core.utilities.ProgressTracker.setCurrentStep(ProgressTracker.kt:114) ~[corda-core-5.0-SNAPSHOT.jar:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:49) ~[?:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:26) ~[?:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:239) ~[corda-node-5.0-SNAPSHOT.jar:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:45) ~[corda-node-5.0-SNAPSHOT.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-5.0-SNAPSHOT.jar:?]
      [INFO ] 2019-04-03T12:42:27,919Z [Node thread-1] statemachine.StaffedFlowHospital.flowErrored - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] admitted to hospital in state StateMachineState(checkpoint=Checkpoint(invocationContext=InvocationContext(origin=RPC(actor=Actor(id=Id(value=demo), serviceId=AuthServiceId(value=NODE_CONFIG), owningLegalIdentity=O=Bank A, L=London, C=GB)), trace=Trace(invocationId=f135433c-8090-43d0-8cdd-6717cc089b40, timestamp: 2019-04-03T12:42:05.503Z, entityType: Invocation, sessionId=638cfb81-6242-46cc-b92c-8719a7e38506, timestamp: 2019-04-03T12:41:51.053Z, entityType: Session), actor=Actor(id=Id(value=demo), serviceId=AuthServiceId(value=NODE_CONFIG), owningLegalIdentity=O=Bank A, L=London, C=GB), externalTrace=null, impersonatedActor=null), ourIdentity=O=Bank A, L=London, C=GB, sessions={}, subFlowStack=[Inlined(flowClass=class net.corda.finance.flows.CashIssueAndPaymentFlow, subFlowVersion=CorDappFlow(platformVersion=5, corDappName=corda-finance-workflows-5.0-SNAPSHOT, corDappHash=9C8458E3436430EA8520E66794A933F7FFA30E57C452768A546DA2B78DE81297), isEnabledTimedFlow=false)], flowState=Unstarted(flowStart=Explicit, frozenFlowLogic=B35BA1BC00D945698B34A1E9EB3611E1F25A3ADE24030A6948D9677C0FDC6E3E), errorState=Clean, numberOfSuspends=0), flowLogic=net.corda.finance.flows.CashIssueAndPaymentFlow@688522b, pendingDeduplicationHandlers=[], isFlowResumed=true, isTransactionTracked=false, isAnyCheckpointPersisted=true, isStartIdempotent=false, isRemoved=false, senderUUID=null) {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      [INFO ] 2019-04-03T12:42:27,928Z [Node thread-1] statemachine.StaffedFlowHospital.invoke - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] has error [0] {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.
      	at net.corda.core.utilities.ProgressTracker.setCurrentStep(ProgressTracker.kt:114) ~[corda-core-5.0-SNAPSHOT.jar:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:49) ~[?:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:26) ~[?:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:239) ~[corda-node-5.0-SNAPSHOT.jar:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:45) ~[corda-node-5.0-SNAPSHOT.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-5.0-SNAPSHOT.jar:?]
      [INFO ] 2019-04-03T12:42:27,933Z [Node thread-1] statemachine.StaffedFlowHospital.flowErrored - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] error allowed to propagate {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      [WARN ] 2019-04-03T12:42:27,977Z [Node thread-1] interceptors.DumpHistoryOnErrorInterceptor.executeTransition - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] errored, dumping all transitions:
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.811Z
        Event: DoRemainingWork
        Actions:
          SignalFlowHasStarted(flowId=[94b42d2e-b2d7-408c-b3f5-f970ad502ee7])
          CreateTransaction
        Continuation: Resume(result=null)
        Diff between previous and next state:
      isFlowResumed:
          false
          true
      
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.935Z
        Event: Error(exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)
        Actions:
          RollbackTransaction
          ScheduleEvent(event=DoRemainingWork)
        Continuation: ProcessEvents
        Diff between previous and next state:
      checkpoint.errorState:
          Clean
          Errored(errors=[FlowError(errorId=-499312209513231693, exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)], propagatedIndex=0, propagating=false)
      isFlowResumed:
          true
          false
      
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.941Z
        Event: DoRemainingWork
        Actions:
      
        Continuation: ProcessEvents
        Diff between previous and next state:
      null
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.943Z
        Event: StartErrorPropagation
        Actions:
          ScheduleEvent(event=DoRemainingWork)
        Continuation: ProcessEvents
        Diff between previous and next state:
      checkpoint.errorState.propagating:
          false
          true
       {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      [WARN ] 2019-04-03T12:42:27,977Z [Node thread-1] interceptors.DumpHistoryOnErrorInterceptor.executeTransition - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] error [errorCode=wnsuw0, moreInformationAt=https://errors.corda.net/OS/5.0-SNAPSHOT/wnsuw0] {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.
      	at net.corda.core.utilities.ProgressTracker.setCurrentStep(ProgressTracker.kt:114) ~[corda-core-5.0-SNAPSHOT.jar:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:49) ~[?:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:26) ~[?:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:239) ~[corda-node-5.0-SNAPSHOT.jar:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:45) ~[corda-node-5.0-SNAPSHOT.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-5.0-SNAPSHOT.jar:?]
      [WARN ] 2019-04-03T12:42:27,990Z [Node thread-1] statemachine.ActionExecutorImpl.executePropagateErrors - Propagating error {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      [WARN ] 2019-04-03T12:42:28,058Z [Node thread-1] interceptors.DumpHistoryOnErrorInterceptor.executeTransition - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] errored, dumping all transitions:
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.811Z
        Event: DoRemainingWork
        Actions:
          SignalFlowHasStarted(flowId=[94b42d2e-b2d7-408c-b3f5-f970ad502ee7])
          CreateTransaction
        Continuation: Resume(result=null)
        Diff between previous and next state:
      isFlowResumed:
          false
          true
      
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.935Z
        Event: Error(exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)
        Actions:
          RollbackTransaction
          ScheduleEvent(event=DoRemainingWork)
        Continuation: ProcessEvents
        Diff between previous and next state:
      checkpoint.errorState:
          Clean
          Errored(errors=[FlowError(errorId=-499312209513231693, exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)], propagatedIndex=0, propagating=false)
      isFlowResumed:
          true
          false
      
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.941Z
        Event: DoRemainingWork
        Actions:
      
        Continuation: ProcessEvents
        Diff between previous and next state:
      null
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:27.943Z
        Event: StartErrorPropagation
        Actions:
          ScheduleEvent(event=DoRemainingWork)
        Continuation: ProcessEvents
        Diff between previous and next state:
      checkpoint.errorState.propagating:
          false
          true
      
      
       --- Transition of flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] ---
        Timestamp: 2019-04-03T12:42:28.051Z
        Event: DoRemainingWork
        Actions:
          PropagateErrors(errorMessages=[ErrorSessionMessage(flowException=null, errorId=-499312209513231693)], sessions=[], senderUUID=null)
          CreateTransaction
          RemoveCheckpoint(id=[94b42d2e-b2d7-408c-b3f5-f970ad502ee7])
          PersistDeduplicationFacts(deduplicationHandlers=[])
          ReleaseSoftLocks(uuid=94b42d2e-b2d7-408c-b3f5-f970ad502ee7)
          CommitTransaction
          AcknowledgeMessages(deduplicationHandlers=[])
          RemoveSessionBindings(sessionIds=[])
          RemoveFlow(flowId=[94b42d2e-b2d7-408c-b3f5-f970ad502ee7], removalReason=ErrorFinish(flowErrors=[FlowError(errorId=-499312209513231693, exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)]), lastState=StateMachineState(checkpoint=Checkpoint(invocationContext=InvocationContext(origin=RPC(actor=Actor(id=Id(value=demo), serviceId=AuthServiceId(value=NODE_CONFIG), owningLegalIdentity=O=Bank A, L=London, C=GB)), trace=Trace(invocationId=f135433c-8090-43d0-8cdd-6717cc089b40, timestamp: 2019-04-03T12:42:05.503Z, entityType: Invocation, sessionId=638cfb81-6242-46cc-b92c-8719a7e38506, timestamp: 2019-04-03T12:41:51.053Z, entityType: Session), actor=Actor(id=Id(value=demo), serviceId=AuthServiceId(value=NODE_CONFIG), owningLegalIdentity=O=Bank A, L=London, C=GB), externalTrace=null, impersonatedActor=null), ourIdentity=O=Bank A, L=London, C=GB, sessions={}, subFlowStack=[Inlined(flowClass=class net.corda.finance.flows.CashIssueAndPaymentFlow, subFlowVersion=CorDappFlow(platformVersion=5, corDappName=corda-finance-workflows-5.0-SNAPSHOT, corDappHash=9C8458E3436430EA8520E66794A933F7FFA30E57C452768A546DA2B78DE81297), isEnabledTimedFlow=false)], flowState=Unstarted(flowStart=Explicit, frozenFlowLogic=B35BA1BC00D945698B34A1E9EB3611E1F25A3ADE24030A6948D9677C0FDC6E3E), errorState=Errored(errors=[FlowError(errorId=-499312209513231693, exception=java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.)], propagatedIndex=1, propagating=true), numberOfSuspends=0), flowLogic=net.corda.finance.flows.CashIssueAndPaymentFlow@688522b, pendingDeduplicationHandlers=[], isFlowResumed=false, isTransactionTracked=false, isAnyCheckpointPersisted=true, isStartIdempotent=false, isRemoved=true, senderUUID=null))
        Continuation: Abort
        Diff between previous and next state:
      isRemoved:
          false
          true
      checkpoint.errorState.propagatedIndex:
          0
          1
       {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      [WARN ] 2019-04-03T12:42:28,058Z [Node thread-1] interceptors.DumpHistoryOnErrorInterceptor.executeTransition - Flow [94b42d2e-b2d7-408c-b3f5-f970ad502ee7] error [errorCode=wnsuw0, moreInformationAt=https://errors.corda.net/OS/5.0-SNAPSHOT/wnsuw0] {actor_id=demo, actor_owning_identity=O=Bank A, L=London, C=GB, actor_store_id=NODE_CONFIG, fiber-id=10000001, flow-id=94b42d2e-b2d7-408c-b3f5-f970ad502ee7, invocation_id=f135433c-8090-43d0-8cdd-6717cc089b40, invocation_timestamp=2019-04-03T12:42:05.503Z, origin=demo, session_id=638cfb81-6242-46cc-b92c-8719a7e38506, session_timestamp=2019-04-03T12:41:51.053Z, thread-id=164}
      java.lang.IllegalArgumentException: Step Issuing cash not found in progress tracker.
      	at net.corda.core.utilities.ProgressTracker.setCurrentStep(ProgressTracker.kt:114) ~[corda-core-5.0-SNAPSHOT.jar:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:49) ~[?:?]
      	at net.corda.finance.flows.CashIssueAndPaymentFlow.call(CashIssueAndPaymentFlow.kt:26) ~[?:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:239) ~[corda-node-5.0-SNAPSHOT.jar:?]
      	at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:45) ~[corda-node-5.0-SNAPSHOT.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-5.0-SNAPSHOT.jar:?]
      

      Update:

      The issue is that the ProgressTracker.Step class does not implement: equals/hashcode and thus deserialized Steps do not match the steps from the instantiated progress tracker.

        Attachments

          Activity

            People

            • Assignee:
              Tudor.Malene Tudor Malene
              Reporter:
              Tudor.Malene Tudor Malene
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: