wildfly-extras / wildfly-jar-maven-plugin

WildFly Bootable JAR
https://docs.wildfly.org/bootablejar/
Apache License 2.0
57 stars 40 forks source link

RejectedExecutionException in dev mode with source watching #248

Closed soul2zimate closed 2 years ago

soul2zimate commented 3 years ago

Not sure if this is the right place to report a bug, I didn't find a proper component in Jira.

As in jaxrs example, I have seen RejectedExecutionException when I shut down a dev mode server with source watching (version 5.0.0.Final). This only happens in dev mode.

mvn wildfly-jar:dev-watch 

[INFO] Scanning for projects...
[INFO] 
[INFO] ---------------------< org.wildfly.plugins:jaxrs >----------------------
[INFO] Building WildFly Bootable JAR - JAX-RS Example 5.0.0.Final
[INFO] --------------------------------[ war ]---------------------------------
[INFO] 
[INFO] --- wildfly-jar-maven-plugin:5.0.0.Final:dev-watch (default-cli) @ jaxrs ---
[INFO] Dev mode, adding layer management to ensure dev mode can be operated
[INFO] Provisioning server configuration based on the set of configured layers
[INFO] Building server based on [[wildfly@maven(org.jboss.universe:community-universe)#24.0.0.Final inherit-packages=false inheritConfigs=false]] galleon feature-packs
[INFO] Found boot artifact org.wildfly.core:wildfly-jar-boot:jar:16.0.0.Final:provided in org.wildfly:wildfly-ee-galleon-pack:24.0.0.Final
[INFO] CLI executions are done in forked process
[INFO] Hollow jar, No application deployment added to server.
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /Users/chaowan/work/git/wildfly-extra/wildfly-jar-maven-plugin/examples/jaxrs/src/main/resources
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 2 source files to /Users/chaowan/work/git/wildfly-extra/wildfly-jar-maven-plugin/examples/jaxrs/target/classes
[INFO] Exploding webapp
[INFO] Assembling webapp [jaxrs] in [/Users/chaowan/work/git/wildfly-extra/wildfly-jar-maven-plugin/examples/jaxrs/target/deployments/ROOT.war]
[INFO] Processing war project
[INFO] Webapp assembled in [38 msecs]
Jun 18, 2021 5:10:43 PM org.jboss.threads.Version <clinit>
INFO: JBoss Threads version 2.3.2.Final
Jun 18, 2021 5:10:43 PM org.jboss.remoting3.EndpointImpl <clinit>
INFO: JBoss Remoting version 5.0.8.Final
Jun 18, 2021 5:10:43 PM org.xnio.Xnio <clinit>
INFO: XNIO version 3.6.5.Final
Jun 18, 2021 5:10:43 PM org.xnio.nio.NioXnio <clinit>
INFO: XNIO NIO Implementation Version 3.6.5.Final
Jun 18, 2021 5:10:43 PM org.wildfly.security.Version <clinit>
INFO: ELY00001: WildFly Elytron version 1.6.0.Final
17:10:45,579 INFO  [org.wildfly.jar] (main) WFLYJAR0007: Installed server and application in /var/folders/d8/yvkcdjv17mz_6wz5mlkf8y680000gn/T/wildfly-bootable-server6622534778528915731, took 1593ms
17:10:45,852 INFO  [org.wildfly.jar] (main) WFLYJAR0008: Server options: [--read-only-server-config=standalone.xml]
17:10:45,927 INFO  [org.jboss.msc] (main) JBoss MSC version 1.4.12.Final
17:10:45,933 INFO  [org.jboss.threads] (main) JBoss Threads version 2.4.0.Final
17:10:46,056 INFO  [org.jboss.as] (MSC service thread 1-2) WFLYSRV0049: WildFly Full 24.0.0.Final (WildFly Core 16.0.0.Final) starting
17:10:46,634 INFO  [org.wildfly.security] (ServerService Thread Pool -- 7) ELY00001: WildFly Elytron version 1.16.0.Final
17:10:46,868 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0039: Creating http management service using socket-binding (management-http)
17:10:46,881 INFO  [org.xnio] (MSC service thread 1-8) XNIO version 3.8.4.Final
17:10:46,887 INFO  [org.xnio.nio] (MSC service thread 1-8) XNIO NIO Implementation Version 3.8.4.Final
17:10:46,915 INFO  [org.wildfly.extension.microprofile.config.smallrye] (ServerService Thread Pool -- 17) WFLYCONF0001: Activating MicroProfile Config Subsystem
17:10:46,917 INFO  [org.wildfly.extension.io] (ServerService Thread Pool -- 15) WFLYIO001: Worker 'default' has auto-configured to 16 IO threads with 128 max task threads based on your 8 available processors
17:10:46,918 INFO  [org.jboss.as.naming] (ServerService Thread Pool -- 18) WFLYNAM0001: Activating Naming Subsystem
17:10:46,938 INFO  [org.jboss.as.jaxrs] (ServerService Thread Pool -- 16) WFLYRS0016: RESTEasy version 3.15.1.Final
17:10:46,940 INFO  [org.jboss.remoting] (MSC service thread 1-7) JBoss Remoting version 5.0.23.Final
17:10:46,940 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) WFLYUT0003: Undertow 2.2.8.Final starting
17:10:46,941 INFO  [org.jboss.as.naming] (MSC service thread 1-1) WFLYNAM0003: Starting Naming Service
17:10:46,998 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0012: Started server default-server.
17:10:47,000 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-5) Queuing requests.
17:10:47,005 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0018: Host default-host starting
17:10:47,036 WARN  [org.wildfly.extension.elytron] (MSC service thread 1-8) WFLYELY00023: KeyStore file '/var/folders/d8/yvkcdjv17mz_6wz5mlkf8y680000gn/T/wildfly-bootable-server6622534778528915731/standalone/configuration/application.keystore' does not exist. Used blank.
17:10:47,047 WARN  [org.wildfly.extension.elytron] (MSC service thread 1-1) WFLYELY01084: KeyStore /var/folders/d8/yvkcdjv17mz_6wz5mlkf8y680000gn/T/wildfly-bootable-server6622534778528915731/standalone/configuration/application.keystore not found, it will be auto generated on first use with a self-signed certificate for host localhost
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.wildfly.extension.elytron.SSLDefinitions (jar:file:/var/folders/d8/yvkcdjv17mz_6wz5mlkf8y680000gn/T/wildfly-bootable-server6622534778528915731/modules/system/layers/base/org/wildfly/extension/elytron/main/wildfly-elytron-integration-16.0.0.Final.jar!/) to method com.sun.net.ssl.internal.ssl.Provider.isFIPS()
WARNING: Please consider reporting this to the maintainers of org.wildfly.extension.elytron.SSLDefinitions
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
17:10:47,069 WARN  [org.jboss.as.domain.http.api.undertow] (MSC service thread 1-8) WFLYDMHTTP0003: Unable to load console module for slot main, disabling console
17:10:47,072 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0006: Undertow HTTP listener default listening on 127.0.0.1:8080
17:10:47,176 INFO  [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0212: Resuming server
17:10:47,177 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: WildFly Full 24.0.0.Final (WildFly Core 16.0.0.Final) started in 1321ms - Started 114 of 120 services (30 services are lazy, passive or on-demand)
17:10:47,179 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:9990/management
17:10:47,180 INFO  [org.jboss.as] (Controller Boot Thread) WFLYSRV0054: Admin console is not enabled
17:10:47,523 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-4) WFLYSRV0027: Starting deployment of "ROOT.war" (runtime-name: "ROOT.war")
17:10:48,823 INFO  [org.jboss.resteasy.resteasy_jaxrs.i18n] (ServerService Thread Pool -- 9) RESTEASY002225: Deploying javax.ws.rs.core.Application: class org.wildfly.plugins.demo.jaxrs.RestApplication
17:10:48,865 INFO  [org.hibernate.validator.internal.util.Version] (ServerService Thread Pool -- 9) HV000001: Hibernate Validator 6.0.22.Final
17:10:48,920 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 9) WFLYUT0021: Registered web context: '/' for server 'default-server'
17:10:48,959 INFO  [org.jboss.as.server] (management-handler-thread - 1) WFLYSRV0010: Deployed "ROOT.war" (runtime-name : "ROOT.war")
^C17:11:06,454 INFO  [org.jboss.as.server] (Thread-2) WFLYSRV0272: Suspending server
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
17:11:06,456 INFO  [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested via an OS signal
[INFO] Total time:  42.845 s
[INFO] Finished at: 2021-06-18T17:11:06+08:00
[INFO] ------------------------------------------------------------------------
17:11:06,465 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 9) WFLYUT0022: Unregistered web context: '/' from server 'default-server'
17:11:06,466 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0008: Undertow HTTP listener default suspending
17:11:06,467 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-2) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 127.0.0.1:8080
17:11:06,471 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0019: Host default-host stopping
17:11:06,472 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0004: Undertow 2.2.8.Final stopping
17:11:06,482 ERROR [org.xnio.listener] (management I/O-2) XNIO001007: A channel event listener threw an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
    at org.jboss.xnio.nio@3.8.4.Final//org.xnio.nio.WorkerThread.execute(WorkerThread.java:620)
    at org.jboss.remoting@5.0.23.Final//org.jboss.remoting3.remote.RemoteConnection$RemoteWriteListener.send(RemoteConnection.java:373)
    at org.jboss.remoting@5.0.23.Final//org.jboss.remoting3.remote.RemoteConnection.send(RemoteConnection.java:127)
    at org.jboss.remoting@5.0.23.Final//org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial.sendCapabilities(ServerConnectionOpenListener.java:439)
    at org.jboss.remoting@5.0.23.Final//org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial.handleEvent(ServerConnectionOpenListener.java:239)
    at org.jboss.remoting@5.0.23.Final//org.jboss.remoting3.remote.ServerConnectionOpenListener$Initial.handleEvent(ServerConnectionOpenListener.java:142)
    at org.jboss.xnio@3.8.4.Final//org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
    at org.jboss.xnio@3.8.4.Final//org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66)
    at org.jboss.xnio.nio@3.8.4.Final//org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89)
    at org.jboss.xnio.nio@3.8.4.Final//org.xnio.nio.WorkerThread.run(WorkerThread.java:591)

17:11:06,491 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-3) WFLYSRV0028: Stopped deployment ROOT.war (runtime-name: ROOT.war) in 31ms
17:11:06,496 INFO  [org.jboss.as] (MSC service thread 1-5) WFLYSRV0050: WildFly Full 24.0.0.Final (WildFly Core 16.0.0.Final) stopped in 37ms
jamezp commented 3 years ago

@soul2zimate This is the correct place :)

Do you see this error every time? It looks like it might be something in a shutdown hook so likely not a real issue, but I do understand it looks concerning.

soul2zimate commented 3 years ago

no, it doesn't appear every time, but quite often.

soul2zimate commented 3 years ago

It seems the graceful shutdown operation at line https://github.com/wildfly-extras/wildfly-jar-maven-plugin/blob/5.0.1.Final/plugin/src/main/java/org/wildfly/plugins/bootablejar/maven/goals/DevWatchBootableJarMojo.java#L936 sometimes can lead to this. And yes, it's probably not harmful.

jfdenise commented 2 years ago

Closing this issue, the trace is harmless.