TestWorkflowEnvironment#sleep hangs indefinitely

Comienza con la reproducción enlazada de TemporalSleepBugApplicationTests.java, especialmente con la línea 52, y luego sigue TestWorkflowEnvironmentInternal.sleep a través de TestService.unlockTimeSkippingWithSleep y unlockTimeSkippingWhileSleep. Compara el comportamiento cuando se ejecutan ambos workflows con el caso en el que se elimina CreateCustomerWorkflow. La tarea está terminada cuando la reproducción finaliza sin una espera indefinida ni un deadlock.

Actual Behavior

Under certain execution path io.temporal.testing.TestWorkflowEnvironment#sleep hangs indefinitely.

Steps to Reproduce the Problem

Please have a look at https://github.com/rpost/temporal-java-sdk-bug-2670/blob/main/src/test/java/com/example/temporalsleepbug/TemporalSleepBugApplicationTests.java

Execution stops at https://github.com/rpost/temporal-java-sdk-bug-2670/blob/main/src/test/java/com/example/temporalsleepbug/TemporalSleepBugApplicationTests.java#L52 and never finishes.

Thread dump shows:

"main" #1 [1711914] prio=5 os_prio=0 cpu=2324,38ms elapsed=23,31s tid=0x00007cac5c033e30 nid=1711914 waiting on condition  [0x00007cac60512000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
	- parking to wait for  <0x00000002b9220bc8> (a io.grpc.stub.ClientCalls$ThreadlessExecutor)
	at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:221)
	at io.grpc.stub.ClientCalls$ThreadlessExecutor.waitAndDrain(ClientCalls.java:717)
	at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:159)
	at io.temporal.api.testservice.v1.TestServiceGrpc$TestServiceBlockingStub.unlockTimeSkippingWithSleep(TestServiceGrpc.java:586)
	at io.temporal.testing.TestWorkflowEnvironmentInternal.sleep(TestWorkflowEnvironmentInternal.java:165)
	at com.example.temporalsleepbug.TemporalSleepBugApplicationTests.shouldExecuteWorkflow(TemporalSleepBugApplicationTests.java:52)
	at java.lang.invoke.LambdaForm$DMH/0x00007cabc8170800.invokeVirtual([email protected]/LambdaForm$DMH)
	at java.lang.invoke.LambdaForm$MH/0x00007cabc86b8000.invoke([email protected]/LambdaForm$MH)
	at java.lang.invoke.Invokers$Holder.invokeExact_MT([email protected]/Invokers$Holder)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl([email protected]/DirectMethodHandleAccessor.java:153)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke([email protected]/DirectMethodHandleAccessor.java:103)
	at java.lang.reflect.Method.invoke([email protected]/Method.java:580)
	at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:775)
	....

"workflow-method-SubscriberTerminationWorkflow-1234-84b7b4fc-bea0-42f3-a168-fb8ebac7c408" #71 [1712086] prio=5 os_prio=0 cpu=4,69ms elapsed=20,45s tid=0x00007caaf80059f0 nid=1712086 waiting on condition  [0x00007cac14629000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
	- parking to wait for  <0x00000007ffd017e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:371)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block([email protected]/AbstractQueuedSynchronizer.java:519)
	at java.util.concurrent.ForkJoinPool.unmanagedBlock([email protected]/ForkJoinPool.java:3780)
	at java.util.concurrent.ForkJoinPool.managedBlock([email protected]/ForkJoinPool.java:3725)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await([email protected]/AbstractQueuedSynchronizer.java:1712)
	at io.temporal.internal.sync.WorkflowThreadScheduler.yieldLocked(WorkflowThreadScheduler.java:37)
	at io.temporal.internal.sync.WorkflowThreadContext.yield(WorkflowThreadContext.java:70)
	at io.temporal.internal.sync.WorkflowThreadImpl.yield(WorkflowThreadImpl.java:378)
	at io.temporal.internal.sync.WorkflowThread.await(WorkflowThread.java:27)
	at io.temporal.internal.sync.SyncWorkflowContext.await(SyncWorkflowContext.java:1290)
	at io.temporal.internal.sync.WorkflowInternal.await(WorkflowInternal.java:510)
	at io.temporal.workflow.Workflow.await(Workflow.java:611)
	at com.example.temporalsleepbug.SubscriberTerminationWorkflow$SubscriberTerminationWorkflowImpl.execute(SubscriberTerminationWorkflow.java:25)
	at java.lang.invoke.LambdaForm$DMH/0x00007cabc8778000.invokeInterface([email protected]/LambdaForm$DMH)
	at java.lang.invoke.LambdaForm$MH/0x00007cabc8778c00.invoke([email protected]/LambdaForm$MH)
	at java.lang.invoke.Invokers$Holder.invokeExact_MT([email protected]/Invokers$Holder)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl([email protected]/DirectMethodHandleAccessor.java:154)
	at jdk.internal.reflect.DirectMethodHandleAccessor.invoke([email protected]/DirectMethodHandleAccessor.java:103)
	at java.lang.reflect.Method.invoke([email protected]/Method.java:580)
	at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation$RootWorkflowInboundCallsInterceptor.execute(POJOWorkflowImplementationFactory.java:406)
	at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation.execute(POJOWorkflowImplementationFactory.java:354)
	at io.temporal.internal.sync.WorkflowExecutionHandler.runWorkflowMethod(WorkflowExecutionHandler.java:51)
	at io.temporal.internal.sync.SyncWorkflow.lambda$start$0(SyncWorkflow.java:122)
	at io.temporal.internal.sync.SyncWorkflow$$Lambda/0x00007cabc8743860.run(Unknown Source)
	at io.temporal.internal.sync.CancellationScopeImpl.run(CancellationScopeImpl.java:99)
	at io.temporal.internal.sync.WorkflowThreadImpl$RunnableWrapper.run(WorkflowThreadImpl.java:92)
	at io.temporal.worker.ActiveThreadReportingExecutor.lambda$submit$0(ActiveThreadReportingExecutor.java:34)
	at io.temporal.worker.ActiveThreadReportingExecutor$$Lambda/0x00007cabc8741dc0.run(Unknown Source)
	at java.util.concurrent.Executors$RunnableAdapter.call([email protected]/Executors.java:572)
	at java.util.concurrent.FutureTask.run$$$capture([email protected]/FutureTask.java:317)
	at java.util.concurrent.FutureTask.run([email protected]/FutureTask.java)
	at java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/ThreadPoolExecutor.java:1144)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/ThreadPoolExecutor.java:642)
	at java.lang.Thread.runWith([email protected]/Thread.java:1596)
	at java.lang.Thread.run([email protected]/Thread.java:1583)

"grpc-default-executor-5" #63 [1712078] daemon prio=5 os_prio=0 cpu=134,75ms elapsed=20,72s tid=0x00007cac5fec8ce0 nid=1712078 waiting on condition  [0x00007cac14e2a000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
	- parking to wait for  <0x00000002b9358e08> (a java.util.concurrent.CompletableFuture$Signaller)
	at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:221)
	at java.util.concurrent.CompletableFuture$Signaller.block([email protected]/CompletableFuture.java:1864)
	at java.util.concurrent.ForkJoinPool.unmanagedBlock([email protected]/ForkJoinPool.java:3780)
	at java.util.concurrent.ForkJoinPool.managedBlock([email protected]/ForkJoinPool.java:3725)
	at java.util.concurrent.CompletableFuture.waitingGet([email protected]/CompletableFuture.java:1898)
	at java.util.concurrent.CompletableFuture.get([email protected]/CompletableFuture.java:2072)
	at io.temporal.internal.testservice.TestService.unlockTimeSkippingWhileSleep(TestService.java:126)
	at io.temporal.internal.testservice.TestService.unlockTimeSkippingWithSleep(TestService.java:95)
	at io.temporal.api.testservice.v1.TestServiceGrpc$MethodHandlers.invoke(TestServiceGrpc.java:747)
	at io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:182)
	at io.grpc.PartialForwardingServerCallListener.onHalfClose(PartialForwardingServerCallListener.java:35)
	at io.grpc.ForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:23)
	at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:351)
	at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:860)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133)
	at java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/ThreadPoolExecutor.java:1144)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/ThreadPoolExecutor.java:642)
	at java.lang.Thread.runWith([email protected]/Thread.java:1596)
	at java.lang.Thread.run([email protected]/Thread.java:1583)

What is interesting is when I comment:

        CreateCustomerWorkflow createCustomerWorkflow = workflowClient.newWorkflowStub(
                CreateCustomerWorkflow.class,
                WorkflowOptions.newBuilder()
                        .setWorkflowId(CreateCustomerWorkflow.class.getSimpleName() + "-" + 1234L)
                        .setTaskQueue(TemporalSleepBugApplication.TASK_QUEUE)
                        .build()
        );
        WorkflowClient.execute(createCustomerWorkflow::execute, 1234L);

        Thread.sleep(5000); // let previous workflow complete

out and leave only SubscriberTerminationWorkflow in test then everything runs fine, without deadlocks.

Specifications

• Version: 1.31.0
• Platform: n/a