Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-17186

Wrong exception handling by ManagedScheduledExecutorService.schedule(...)

    XMLWordPrintable

Details

    • Hide
      • Start the WildFly server
      • Unpack the attached small deployment project
      • From its directory build and deploy it (assuming the server is in ~/wildfly), Java 17 is required:

      $ ./gradlew clean war && cp build/libs/executor-service.war ~/wildfly/standalone/deployments/

      • Check the server output:

      18:25:51,556 INFO  [org.jboss.as.repository] (DeploymentScanner-threads - 1) WFLYDR0001: Content added at location /home/paul/versions/wildfly-26.1.1.Final/standalone/data/content/d3/c7f109e6c97e9862995edc97e663779b364084/content
      18:25:51,561 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool – 23) WFLYUT0022: Unregistered web context: '/executor-service' from server 'default-server'
      18:25:51,571 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0028: Stopped deployment executor-service.war (runtime-name: executor-service.war) in 12ms
      18:25:51,581 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0027: Starting deployment of "executor-service.war" (runtime-name: "executor-service.war")
      18:25:51,791 INFO  [stdout] (ServerService Thread Pool – 88) STARTED
      18:25:51,794 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool – 88) WFLYUT0021: Registered web context: '/executor-service' for server 'default-server'
      18:25:51,816 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 1) WFLYSRV0016: Replaced deployment "executor-service.war" with deployment "executor-service.war"
      18:25:51,818 INFO  [org.jboss.as.repository] (DeploymentScanner-threads - 1) WFLYDR0002: Content removed from location /home/paul/versions/wildfly-26.1.1.Final/standalone/data/content/9e/5d617b2df1256354674cdb2c77e79917c26ec5/content
      18:25:53,794 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) TESTING
      18:25:53,799 INFO  [stdout] (EE-ManagedExecutorService-default-Thread-7) TASK 0
      18:25:53,801 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: 0
      18:25:53,804 INFO  [stdout] (EE-ManagedExecutorService-default-Thread-8) TASK 1
      18:25:53,806 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.RuntimeException: task '1' failure; should be propagated
      18:25:53,808 INFO  [stdout] (EE-ManagedScheduledExecutorService-default-Thread-5) TASK A
      18:25:53,809 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: A
      18:25:53,811 INFO  [stdout] (EE-ManagedScheduledExecutorService-default-Thread-3) TASK B
      18:25:53,812 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.RuntimeException: task 'B' failure; should be propagated
      18:25:54,814 INFO  [stdout] (EE-ManagedScheduledExecutorService-default-Thread-6) TASK C
      18:25:54,815 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: C
      18:25:56,817 INFO  [stdout] (EE-ManagedScheduledExecutorService-default-Thread-2) TASK D
      18:25:56,818 ERROR [org.jboss.as.ee] (EE-ManagedScheduledExecutorService-default-Thread-2) WFLYEE0110: Failed to run scheduled task: java.lang.RuntimeException: task 'D' failure; should be propagated
              at deployment.executor-service.war//foo.Bootstrap.failJob(Bootstrap.java:75)
              [...]
              at org.glassfish.javax.enterprise.concurrent//org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:227)

      18:25:56,820 INFO  [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: WFLYEE0111: Cannot run scheduled task foo.Bootstrap$$Lambda$1386/0x000000080184c000@51ba64ae as container is suspended

      It's task D that is misbehaving. Source code contains some comments that you can read and also a prepared (but not activated) change to using stdlib Executors.newScheduledThreadPool() that doesn't exhibit this bug.

      Another suspicious point is that WildFly throws an exception saying that "container is suspended". Note, however, that this hasn't prevented five other tasks from behaving properly. I also added that 'Thread.sleep (2000)' in the beginning to try and get rid of this, but the delay changed nothing, so I suspect the claim that "container is suspended" is simply wrong.

      Show
      Start the WildFly server Unpack the attached small deployment project From its directory build and deploy it (assuming the server is in ~/wildfly), Java 17 is required: $ ./gradlew clean war && cp build/libs/executor-service.war ~/wildfly/standalone/deployments/ Check the server output: 18:25:51,556 INFO   [org.jboss.as.repository] (DeploymentScanner-threads - 1) WFLYDR0001: Content added at location /home/paul/versions/wildfly-26.1.1.Final/standalone/data/content/d3/c7f109e6c97e9862995edc97e663779b364084/content 18:25:51,561 INFO   [org.wildfly.extension.undertow] (ServerService Thread Pool – 23) WFLYUT0022: Unregistered web context: '/executor-service' from server 'default-server' 18:25:51,571 INFO   [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0028: Stopped deployment executor-service.war (runtime-name: executor-service.war) in 12ms 18:25:51,581 INFO   [org.jboss.as.server.deployment] (MSC service thread 1-2) WFLYSRV0027: Starting deployment of "executor-service.war" (runtime-name: "executor-service.war") 18:25:51,791 INFO   [stdout] (ServerService Thread Pool – 88) STARTED 18:25:51,794 INFO   [org.wildfly.extension.undertow] (ServerService Thread Pool – 88) WFLYUT0021: Registered web context: '/executor-service' for server 'default-server' 18:25:51,816 INFO   [org.jboss.as.server] (DeploymentScanner-threads - 1) WFLYSRV0016: Replaced deployment "executor-service.war" with deployment "executor-service.war" 18:25:51,818 INFO   [org.jboss.as.repository] (DeploymentScanner-threads - 1) WFLYDR0002: Content removed from location /home/paul/versions/wildfly-26.1.1.Final/standalone/data/content/9e/5d617b2df1256354674cdb2c77e79917c26ec5/content 18:25:53,794 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) TESTING 18:25:53,799 INFO   [stdout] (EE-ManagedExecutorService-default-Thread-7) TASK 0 18:25:53,801 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: 0 18:25:53,804 INFO   [stdout] (EE-ManagedExecutorService-default-Thread-8) TASK 1 18:25:53,806 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.RuntimeException: task '1' failure; should be propagated 18:25:53,808 INFO   [stdout] (EE-ManagedScheduledExecutorService-default-Thread-5) TASK A 18:25:53,809 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: A 18:25:53,811 INFO   [stdout] (EE-ManagedScheduledExecutorService-default-Thread-3) TASK B 18:25:53,812 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.RuntimeException: task 'B' failure; should be propagated 18:25:54,814 INFO   [stdout] (EE-ManagedScheduledExecutorService-default-Thread-6) TASK C 18:25:54,815 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task succeeded; result: C 18:25:56,817 INFO   [stdout] (EE-ManagedScheduledExecutorService-default-Thread-2) TASK D 18:25:56,818 ERROR [org.jboss.as.ee] (EE-ManagedScheduledExecutorService-default-Thread-2) WFLYEE0110: Failed to run scheduled task: java.lang.RuntimeException: task 'D' failure; should be propagated         at deployment.executor-service.war//foo.Bootstrap.failJob(Bootstrap.java:75)         [...]         at org.glassfish.javax.enterprise.concurrent//org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:227) 18:25:56,820 INFO   [stdout] (EE-ManagedThreadFactory-default-Thread-5) task failed with an exception: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: WFLYEE0111: Cannot run scheduled task foo.Bootstrap$$Lambda$1386/0x000000080184c000@51ba64ae as container is suspended It's task D that is misbehaving. Source code contains some comments that you can read and also a prepared (but not activated) change to using stdlib Executors.newScheduledThreadPool() that doesn't exhibit this bug. Another suspicious point is that WildFly throws an exception saying that "container is suspended". Note, however, that this hasn't prevented five other tasks from behaving properly. I also added that 'Thread.sleep (2000)' in the beginning to try and get rid of this, but the delay changed nothing, so I suspect the claim that "container is suspended" is simply wrong.
    • ---
    • ---

    Description

      A task submitted to a ScheduledExecutorService that fails with an exception, doesn't propagate said exception to the resulting Future, wrapped in an ExecutionException. In comparison, this works with WildFly-provided services if submit() is used (not schedule()) and also in built-in Executors.newScheduledThreadPool() regardless of whether submit() or schedule() is used.

      Attachments

        Activity

          People

            bstansbe@redhat.com Brian Stansberry
            doublep_ Paul Pogonyshev (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: