Bug Report: Race Condition in Executors with enabled threadlifetimeseconds option/FISH-6338

[s-macke]

Description

---

With enabled managed executor option --threadlifetimeseconds=60 we often get the exception in the logs

org.glassfish.api.invocation.InvocationException: No invocation on invocation stack. Expected invocation: [email protected]
	componentId=my-service_/
	type=SERVLET_INVOCATION
	instance=org.glassfish.jersey.servlet.ServletContainer@a3c0a21
	container=StandardEngine[glassfish-web].StandardHost[server].StandardContext[]
	appName=my-service

This exception is thrown after around 30-100 executor runs, statistically. This exception even occurs when the tasks are run sequentially. So only one task is active in any moment. This exception also occurs, when the run time of the task is limited to 1 second.

Expected Outcome

No exception after the executor run

Current Outcome

Exception can be found very often in the log.

Steps to reproduce

create an executor such as

create-managed-executor-service --corepoolsize=0 --maximumpoolsize=200 --threadlifetimeseconds=60 concurrent/myCaller

and run several hundred tasks with at least a runtime of second on it and check for exceptions.

Analysis

In the class java.util.concurrent.Threadpoolexecutor the method afterExecute() can be called twice.

As you can see in the picture, a ThreadExpiredException was thrown at some point.

So, if an exception happens in the first afterExecute() function afterExecute() is executed a second time. As result postInvoke() in org.glassfish.api.invocation.InvocationManagerImpl is executed twice for the same task. The second time the InvocationFrames stack is empty and runs into the InvocationException we see above.

In the end, this could be also an JDK Bug. Not sure about it.

Environment

• Payara Micro: 5.2021.10
• Distribution: Distroless
• JDK Version: OpenJDK 11
• Operating System: Linux inside Docker container

[shub8968]

Hi @s-macke,

Would you be able to share the reproducer Application in order to reproduce the issue?

[s-macke]

This one is a patch for the javaee/hello-world-rest example in https://github.com/payara/Payara-Examples

diff --git a/javaee/hello-world-rest/build_and_run.sh b/javaee/hello-world-rest/build_and_run.sh
new file mode 100755
index 0000000..cf08425
--- /dev/null
+++ b/javaee/hello-world-rest/build_and_run.sh
@@ -0,0 +1,2 @@
+mvn clean install
+java -jar payara-micro-5.2022.2.jar --postbootcommandfile postboot.conf --deploy target/hello-world-rest-1.0-SNAPSHOT.war
diff --git a/javaee/hello-world-rest/call.sh b/javaee/hello-world-rest/call.sh
new file mode 100755
index 0000000..6601a3d
--- /dev/null
+++ b/javaee/hello-world-rest/call.sh
@@ -0,0 +1,6 @@
+#!/bin/bash
+while true
+do
+        curl localhost:8080/hello-world-rest-1.0-SNAPSHOT/hello
+done
+
diff --git a/javaee/hello-world-rest/postboot.conf b/javaee/hello-world-rest/postboot.conf
new file mode 100644
index 0000000..12c528d
--- /dev/null
+++ b/javaee/hello-world-rest/postboot.conf
@@ -0,0 +1,2 @@
+create-managed-executor-service --corepoolsize=0 --maximumpoolsize=200 --threadlifetimeseconds=1 concurrent/myCaller
+
diff --git a/javaee/hello-world-rest/src/main/java/fish/payara/examples/hello/world/rest/HelloWorldEndpoint.java b/javaee/hello-world-rest/src/main/java/fish/payara/examples/hello/world/rest/HelloWorldEndpoint.java
index b33b451..0620250 100644
--- a/javaee/hello-world-rest/src/main/java/fish/payara/examples/hello/world/rest/HelloWorldEndpoint.java
+++ b/javaee/hello-world-rest/src/main/java/fish/payara/examples/hello/world/rest/HelloWorldEndpoint.java
@@ -1,5 +1,9 @@
 package fish.payara.examples.hello.world.rest;
 
+import javax.annotation.Resource;
+import javax.enterprise.concurrent.ManagedExecutorService;
+import javax.enterprise.context.ApplicationScoped;
+import javax.inject.Inject;
 import javax.ws.rs.GET;
 import javax.ws.rs.Path;
 import javax.ws.rs.Produces;
@@ -7,12 +11,23 @@ import javax.ws.rs.core.MediaType;
 import fish.payara.examples.hello.world.rest.filter.annotations.TracedEndpoint;
 
 @Path("/hello")
+@ApplicationScoped
 public class HelloWorldEndpoint {
 
+    @Resource(lookup = "concurrent/myCaller")
+    private ManagedExecutorService executor;
+
     @GET
     @Produces(MediaType.TEXT_PLAIN)
     @TracedEndpoint
     public String helloWorld() {
+        executor.submit(() -> {
+            try {
+                Thread.sleep(1000);
+            } catch (InterruptedException e) {
+                e.printStackTrace();
+            }
+        });
         return "Hello World!";
     }
 }

Just use ./build_and_run.sh to start the microservice and then ./call.sh to call the service in an infinite loop.

[shub8968]

Hi @s-macke,

I am able to reproduce this issue. I have raised an internal issue with JIRA FISH-6338. Thanks. It may take a while to fix the issue. You are free to submit a PR to fix the issue.