Using Try.on causes infinite loop/waiting in mock network in Corda 3.2?

Question

I am migrating from v 3.0 to v 3.2 and a lot of my unit test uses Try.on to assert some expected result. It was working before in v3.0 but after v3.2 it gets stuck in a infinite wait on the unit test in mock network.

@Test
fun `Issue non-anonymous obligation successfully with non null remark`() {

    // Throw null pointer
    val result = Try.on {
        issueObligation(a, b, 1000.POUNDS, anonymous = false, remark = null)
        network.waitQuiescent()
    }

    assert(result.isFailure)

    // If I don't run this subsequent transaction, the test runs successfully.
    // Somehow, any transaction after a Try.on will get stuck.


    // Should issue successfully.
    issueObligation(a, b, 1000.POUNDS, anonymous = false, remark = "Valid")
    network.waitQuiescent()


}

Stacktrace where by the console will be stuck in infinite wait.

[WARN ] 11:15:45,055 [Mock node 1 thread] (FlowStateMachineImpl.kt:111) flow.[2c41b166-041a-4ec8-87dd-896e3712415e].run - Terminated by unexpected exception {}
java.lang.IllegalArgumentException: Invalid string.
    at net.corda.examples.obligation.flows.IssueObligation$Initiator.call(IssueObligation.kt:44) ~[classes/:?]
    at net.corda.examples.obligation.flows.IssueObligation$Initiator.call(IssueObligation.kt:21) ~[classes/:?]
    at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:96) [corda-node-3.2-corda.jar:?]
    at net.corda.node.services.statemachine.FlowStateMachineImpl.run(FlowStateMachineImpl.kt:44) [corda-node-3.2-corda.jar:?]
    at co.paralleluniverse.fibers.Fiber.run1(Fiber.java:1092) [quasar-core-0.7.9-jdk8.jar:0.7.9]
    at co.paralleluniverse.fibers.Fiber.exec(Fiber.java:788) [quasar-core-0.7.9-jdk8.jar:0.7.9]
    at co.paralleluniverse.fibers.RunnableFiberTask.doExec(RunnableFiberTask.java:100) [quasar-core-0.7.9-jdk8.jar:0.7.9]
    at co.paralleluniverse.fibers.RunnableFiberTask.run(RunnableFiberTask.java:91) [quasar-core-0.7.9-jdk8.jar:0.7.9]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_151]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_151]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_151]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_151]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151]
    at net.corda.node.utilities.AffinityExecutor$ServiceAffinityExecutor$1$thread$1.run(AffinityExecutor.kt:62) [corda-node-3.2-corda.jar:?]
[INFO ] 11:15:45,474 [Mock node 1 thread] (FlowStateMachineImpl.kt:432) flow.[77bea7fa-402f-4527-8388-d910faea6342].initiateSession - Initiating flow session with party O=Mock Company 2, L=London, C=GB. Session id for tracing purposes is SessionId(toLong=7175264157685997907). {}
[INFO ] 11:15:45,570 [Mock node 2 thread] (StateMachineManagerImpl.kt:367) statemachine.StateMachineManagerImpl.onSessionInit - Accepting flow session from party O=Mock Company 1, L=London, C=GB. Session id for tracing purposes is SessionId(toLong=7175264157685997907). {invocation_id=18195f36-850b-4fec-9794-9e57c16f9155, invocation_timestamp=2018-08-03T04:15:45.557Z, session_id=18195f36-850b-4fec-9794-9e57c16f9155, session_timestamp=2018-08-03T04:15:45.557Z}
[INFO ] 11:15:45,747 [Mock node 1 thread] (FlowStateMachineImpl.kt:432) flow.[77bea7fa-402f-4527-8388-d910faea6342].initiateSession - Initiating flow session with party O=Notary Service, L=Zurich, C=CH. Session id for tracing purposes is SessionId(toLong=-6165721234712091944). {}
[INFO ] 11:15:45,772 [Mock node 0 thread] (StateMachineManagerImpl.kt:367) statemachine.StateMachineManagerImpl.onSessionInit - Accepting flow session from party O=Mock Company 1, L=London, C=GB. Session id for tracing purposes is SessionId(toLong=-6165721234712091944). {invocation_id=c7c9d70d-e73a-4724-912a-e7f3d5080e57, invocation_timestamp=2018-08-03T04:15:45.770Z, session_id=c7c9d70d-e73a-4724-912a-e7f3d5080e57, session_timestamp=2018-08-03T04:15:45.770Z}
[INFO ] 11:15:45,868 [Mock node 1 thread] (HibernateConfiguration.kt:47) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Creating session factory for schemas: [ObligationSchemaV1(name=net.corda.examples.obligation.ObligationSchema, version=1)] {}
[INFO ] 11:15:45,875 [Mock node 1 thread] (ConnectionProviderInitiator.java:122) internal.ConnectionProviderInitiator.initiateService - HHH000130: Instantiating explicit connection provider: net.corda.nodeapi.internal.persistence.HibernateConfiguration$NodeDatabaseConnectionProvider {}
[INFO ] 11:15:45,876 [Mock node 1 thread] (Dialect.java:157) dialect.Dialect. - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect {}
[INFO ] 11:15:45,881 [Mock node 1 thread] (BasicTypeRegistry.java:148) type.BasicTypeRegistry.register - HHH000270: Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@7a7698f4 {}
[INFO ] 11:15:45,894 [Mock node 1 thread] (DdlTransactionIsolatorNonJtaImpl.java:47) connections.access.getIsolatedConnection - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@736e95ad] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. {}
[INFO ] 11:15:45,909 [Mock node 1 thread] (HibernateConfiguration.kt:64) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Created session factory for schemas: [ObligationSchemaV1(name=net.corda.examples.obligation.ObligationSchema, version=1)] {}
[INFO ] 11:15:45,916 [Mock node 1 thread] (HibernateConfiguration.kt:47) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Creating session factory for schemas: [VaultSchemaV1(name=net.corda.node.services.vault.VaultSchema, version=1)] {}
[INFO ] 11:15:45,923 [Mock node 1 thread] (ConnectionProviderInitiator.java:122) internal.ConnectionProviderInitiator.initiateService - HHH000130: Instantiating explicit connection provider: net.corda.nodeapi.internal.persistence.HibernateConfiguration$NodeDatabaseConnectionProvider {}
[INFO ] 11:15:45,924 [Mock node 1 thread] (Dialect.java:157) dialect.Dialect. - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect {}
[INFO ] 11:15:45,927 [Mock node 1 thread] (BasicTypeRegistry.java:148) type.BasicTypeRegistry.register - HHH000270: Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@7a7698f4 {}
[INFO ] 11:15:45,953 [Mock node 1 thread] (DdlTransactionIsolatorNonJtaImpl.java:47) connections.access.getIsolatedConnection - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@318fb15] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. {}
[INFO ] 11:15:45,994 [Mock node 1 thread] (HibernateConfiguration.kt:64) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Created session factory for schemas: [VaultSchemaV1(name=net.corda.node.services.vault.VaultSchema, version=1)] {}
[INFO ] 11:15:46,003 [Mock node 1 thread] (FlowStateMachineImpl.kt:432) flow.[77bea7fa-402f-4527-8388-d910faea6342].initiateSession - Initiating flow session with party O=Mock Company 2, L=London, C=GB. Session id for tracing purposes is SessionId(toLong=-2453204714770107984). {}
[INFO ] 11:15:46,027 [Mock node 2 thread] (StateMachineManagerImpl.kt:367) statemachine.StateMachineManagerImpl.onSessionInit - Accepting flow session from party O=Mock Company 1, L=London, C=GB. Session id for tracing purposes is SessionId(toLong=-2453204714770107984). {invocation_id=ec8f9d18-73ef-4739-a0cd-84202e590df9, invocation_timestamp=2018-08-03T04:15:46.026Z, session_id=ec8f9d18-73ef-4739-a0cd-84202e590df9, session_timestamp=2018-08-03T04:15:46.026Z}
[INFO ] 11:15:46,084 [Mock node 2 thread] (HibernateConfiguration.kt:47) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Creating session factory for schemas: [ObligationSchemaV1(name=net.corda.examples.obligation.ObligationSchema, version=1)] {}
[INFO ] 11:15:46,099 [Mock node 2 thread] (ConnectionProviderInitiator.java:122) internal.ConnectionProviderInitiator.initiateService - HHH000130: Instantiating explicit connection provider: net.corda.nodeapi.internal.persistence.HibernateConfiguration$NodeDatabaseConnectionProvider {}
[INFO ] 11:15:46,100 [Mock node 2 thread] (Dialect.java:157) dialect.Dialect. - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect {}
[INFO ] 11:15:46,107 [Mock node 2 thread] (BasicTypeRegistry.java:148) type.BasicTypeRegistry.register - HHH000270: Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@7a7698f4 {}
[INFO ] 11:15:46,115 [Mock node 2 thread] (DdlTransactionIsolatorNonJtaImpl.java:47) connections.access.getIsolatedConnection - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@606d0355] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. {}
[INFO ] 11:15:46,129 [Mock node 2 thread] (HibernateConfiguration.kt:64) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Created session factory for schemas: [ObligationSchemaV1(name=net.corda.examples.obligation.ObligationSchema, version=1)] {}
[INFO ] 11:15:46,130 [Mock node 2 thread] (HibernateConfiguration.kt:47) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Creating session factory for schemas: [VaultSchemaV1(name=net.corda.node.services.vault.VaultSchema, version=1)] {}
[INFO ] 11:15:46,134 [Mock node 2 thread] (ConnectionProviderInitiator.java:122) internal.ConnectionProviderInitiator.initiateService - HHH000130: Instantiating explicit connection provider: net.corda.nodeapi.internal.persistence.HibernateConfiguration$NodeDatabaseConnectionProvider {}
[INFO ] 11:15:46,135 [Mock node 2 thread] (Dialect.java:157) dialect.Dialect. - HHH000400: Using dialect: org.hibernate.dialect.H2Dialect {}
[INFO ] 11:15:46,136 [Mock node 2 thread] (BasicTypeRegistry.java:148) type.BasicTypeRegistry.register - HHH000270: Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@7a7698f4 {}
[INFO ] 11:15:46,157 [Mock node 2 thread] (DdlTransactionIsolatorNonJtaImpl.java:47) connections.access.getIsolatedConnection - HHH10001501: Connection obtained from JdbcConnectionAccess [org.hibernate.engine.jdbc.env.internal.JdbcEnvironmentInitiator$ConnectionProviderJdbcConnectionAccess@6b0f595c] for (non-JTA) DDL execution was not in auto-commit mode; the Connection 'local transaction' will be committed and the Connection will be set into auto-commit mode. {}
[INFO ] 11:15:46,175 [Mock node 2 thread] (HibernateConfiguration.kt:64) persistence.HibernateConfiguration.makeSessionFactoryForSchemas - Created session factory for schemas: [VaultSchemaV1(name=net.corda.node.services.vault.VaultSchema, version=1)] {}

Answer 1

This appears to be a bug in Corda 3.2. It is being tracked here: https://github.com/corda/corda/issues/3741.