[CORDA-2825] Progress tracker not reloadable in checkpoints written in Java - JIRA

Details

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

Severity:
Medium
Target Version/s:

Corda 4.1, Corda Enterprise 4
Feature Team:
Select team
Sprint:

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

Reporter:

Tudor Malene

Votes:

0 Vote for this issue

Watchers:

2 Start watching this issue

Dates

Created:

03/Apr/19 2:38 PM

Updated:

09/Apr/19 10:10 AM

Resolved:

05/Apr/19 3:38 PM