search

OpenLiberty / liberty-arquillian

Arquillian Liberty Managed and Remote containers
Apache License 2.0
10 stars 29 forks source link

Unable to stop server after upgrade to 1.0.7 (using `usrDir` property in arquillian.xml) #107

Closed rslemos closed 3 years ago

rslemos commented 3 years ago

After upgrading to liberty-arquillian-managed to 1.0.7, I've configured pom.xml to use the new usrDir property:

  <build>
      <plugin>
        <groupId>io.openliberty.tools</groupId>
        <artifactId>liberty-maven-plugin</artifactId>
        <version>3.3.4</version>
        <configuration>
          <serverName>my-project</serverName>
          <configFile>src/main/liberty/server.xml</configFile>
          <configDirectory>src/main/liberty/local</configDirectory>
          <userDirectory>C:/wlp-usr</userDirectory>
          <arquillianProperties>
            <usrDir>C:/wlp-usr</usrDir>
          </arquillianProperties>
        </configuration>
      </plugin>
  </build>

After this change, liberty-arquillian-managed became unable to stop the server. A java process is left dangling (with open ports and files locked).

Full output for λ mvn test-compile liberty:create liberty:install-feature liberty:configure-arquillian failsafe:integration-test failsafe:verify

[INFO] Scanning for projects...
[INFO]
[INFO] ---------< my-project:my-project >----------
[INFO] Building my-project 1.0.4-SNAPSHOT
[INFO] --------------------------------[ war ]---------------------------------
[INFO]
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ my-project ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory C:\my-project\src\main\resources
[INFO]
[INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ my-project ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 10 source files to C:\my-project\target\classes
[INFO]
[INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ my-project ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO]
[INFO] --- maven-compiler-plugin:3.1:testCompile (default-testCompile) @ my-project ---
[INFO] Changes detected - recompiling the module!
[INFO] Compiling 1 source file to C:\my-project\target\test-classes
[INFO]
[INFO] --- liberty-maven-plugin:3.2.2:create (default-cli) @ my-project ---
[INFO] CWWKM2102I: Using artifact based assembly archive : io.openliberty:openliberty-kernel:null:21.0.0.4:zip.
[INFO] CWWKM2102I: Using installDirectory : C:\my-project\target\liberty\wlp.
[INFO] CWWKM2102I: Using serverName : my-project.
[INFO] CWWKM2102I: Using serverDirectory : C:\wlp-usr\servers\my-project.
[INFO] CWWKM2185I: The liberty-maven-plugin configuration parameter "appsDirectory" value defaults to "apps".
[INFO] Installing assembly...
[INFO] Expanding: C:\Users\rslemos\.m2\repository\io\openliberty\openliberty-kernel\21.0.0.4\openliberty-kernel-21.0.0.4.zip into C:\my-project\target\liberty
[INFO] CWWKM2143I: Server my-project does not exist. Now creating...
[INFO] CWWKM2001I: Invoke command is ["C:\my-project\target\liberty\wlp\bin\server.bat", create, my-project].
[INFO] Servidor my-project criado.
[INFO] CWWKM2129I: Server my-project has been created at C:\wlp-usr\servers\my-project.
[INFO] Copying 4 files to C:\wlp-usr\servers\my-project
[INFO] Copying 1 file to C:\wlp-usr\servers\my-project
[INFO] CWWKM2144I: Update server configuration file server.xml from C:\my-project\src\main\liberty\server.xml.
[INFO] CWWKM2144I: Update server configuration file jvm.options from inlined configuration.
[INFO] CWWKM2144I: Update server configuration file bootstrap.properties from C:\my-project\src\main\liberty\local\bootstrap.properties.
[INFO]
[INFO] --- liberty-maven-plugin:3.2.2:install-feature (default-cli) @ my-project ---
[INFO] CWWKM2102I: Using artifact based assembly archive : io.openliberty:openliberty-kernel:null:21.0.0.4:zip.
[INFO] CWWKM2102I: Using installDirectory : C:\my-project\target\liberty\wlp.
[INFO] CWWKM2102I: Using serverName : my-project.
[INFO] CWWKM2102I: Using serverDirectory : C:\wlp-usr\servers\my-project.
[INFO] Installing features: [jndi-1.0, cdi-2.0, jdbc-4.2, localconnector-1.0, beanvalidation-2.0, mphealth-3.0, jaxrs-2.1]
[INFO] Product validation completed successfully.
[INFO] The following features have been installed: jndi-1.0 cdi-2.0 jdbc-4.2 localConnector-1.0 el-3.0 beanValidation-2.0 servlet-4.0 mpConfig-2.0 json-1.0 mpHealth-3.0 jsonp-1.1 jaxrsClient-2.1 jaxrs-2.1 servlet-3.1
[INFO]
[INFO] --- liberty-maven-plugin:3.2.2:configure-arquillian (default-cli) @ my-project ---
[INFO] CWWKM2102I: Using artifact based assembly archive : io.openliberty:openliberty-kernel:null:21.0.0.4:zip.
[INFO] CWWKM2102I: Using installDirectory : C:\my-project\target\liberty\wlp.
[INFO] CWWKM2102I: Using serverName : my-project.
[INFO] CWWKM2102I: Using serverDirectory : C:\wlp-usr\servers\my-project.
[INFO] Automatically detected the Arquillian Liberty Managed container at the following coordinates: io.openliberty.arquillian:arquillian-liberty-managed.
[INFO]
[INFO] --- maven-failsafe-plugin:3.0.0-M5:integration-test (default-cli) @ my-project ---
[INFO]
[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running br.myPackage.resource.MyResourceIT
Launching my-project (Open Liberty 21.0.0.4/wlp-1.0.51.cl210420210407-0944) on IBM J9 VM, version 8.0.6.10 - pwa6480sr6fp10-20200408_01(SR6 FP10) (en_BR)
[AUDIT   ] CWWKE0001I: The server my-project has been launched.
[AUDIT   ] CWWKG0028A: Processing included configuration resource: C:\wlp-usr\shared\config\jdbc\ojdbc7-12.1.0.2.xml
[AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: C:\wlp-usr\servers\my-project\configDropins\overrides\arquillian-server.xml
[AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: C:\wlp-usr\servers\my-project\configDropins\overrides\liberty-plugin-variable-config.xml
[AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: C:\wlp-usr\servers\my-project\configDropins\overrides\uc_n06_AuthData.xml
[INFO    ] CWWKE0002I: The kernel started after 2.908 seconds
[INFO    ] CWWKF0007I: Feature update started.
[INFO    ] Aries Blueprint packages not available. So namespaces will not be registered
[AUDIT   ] CWWKZ0058I: Monitoring dropins for applications.
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[WARNING ] CWWKZ0014W: The application my-project could not be started as it could not be found at location my-project.war.
[INFO    ] SRVE0169I: Loading Web Module: arquillian-liberty-support.
[INFO    ] SRVE0250I: Web Module arquillian-liberty-support has been bound to default_host.
[INFO    ] SRVE0169I: Loading Web Module: health.
[INFO    ] SRVE0250I: Web Module health has been bound to default_host.
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/arquillian-support/
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/health/
[INFO    ] CWWKO0219I: TCP Channel defaultHttpEndpoint has been started and is now listening for requests on host 127.0.0.1  (IPv4: 127.0.0.1) port 9080.
[INFO    ] SESN8501I: The session manager did not find a persistent storage location; HttpSession objects will be stored in the local application server's memory.
[AUDIT   ] CWWKF0012I: The server installed the following features: [beanValidation-2.0, cdi-2.0, el-3.0, jaxrs-2.1, jaxrsClient-2.1, jdbc-4.2, jndi-1.0, json-1.0, jsonp-1.1, localConnector-1.0, mpConfig-2.0, mpHealth-3.0, servlet-4.0, usr:arquillian-support-1.0].
[INFO    ] CWWKF0008I: Feature update completed in 9.795 seconds.
[AUDIT   ] CWWKF0011I: The my-project server is ready to run a smarter planet. The my-project server started in 12.703 seconds.
[INFO    ] SESN0176I: A new session context will be created for application key default_host/health
[INFO    ] SESN0176I: A new session context will be created for application key default_host/arquillian-support
[INFO    ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation.
[INFO    ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at C:\wlp-usr\servers\my-project\logs\state\plugin-cfg.xml.
[INFO    ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation.
[INFO    ] SRVE0242I: [io.openliberty.microprofile.health.3.0.internal] [/health] [HealthCheckReadinessServlet]: Initialization successful.
[INFO    ] SRVE0242I: [io.openliberty.microprofile.health.3.0.internal] [/health] [HealthCheckServlet]: Initialization successful.
[INFO    ] SRVE0242I: [io.openliberty.microprofile.health.3.0.internal] [/health] [HealthCheckLivenessServlet]: Initialization successful.
[INFO    ] CWWKZ0018I: Starting application 0cd89973-56c1-411b-93d1-546c01680f22.
[INFO    ] CWWKZ0136I: The 0cd89973-56c1-411b-93d1-546c01680f22 application is using the archive file at the C:\wlp-usr\servers\my-project\dropins\0cd89973-56c1-411b-93d1-546c01680f22.war location.
[WARNING ] SRVE9967W: The manifest class path ibmorbtools.jar can not be found in jar file wsjar:file:/C:/dev-env/wlp-usr/servers/my-project/dropins/0cd89973-56c1-411b-93d1-546c01680f22.war!/WEB-INF/lib/tools.jar or its parent.
[WARNING ] SRVE9967W: The manifest class path ibmorbtools.jar can not be found in jar file wsjar:file:/C:/dev-env/wlp-usr/servers/my-project/dropins/0cd89973-56c1-411b-93d1-546c01680f22.war!/WEB-INF/lib/tools.jar or its parent.
[INFO    ] WELD-000900: 3.1.4 (Final)
[INFO    ] HV000001: Hibernate Validator 6.1.7.Final
[INFO    ] SRVE0169I: Loading Web Module: 0cd89973-56c1-411b-93d1-546c01680f22.
[INFO    ] SRVE0250I: Web Module 0cd89973-56c1-411b-93d1-546c01680f22 has been bound to default_host.
[AUDIT   ] CWWKT0016I: Web application available (default_host): http://localhost:9080/0cd89973-56c1-411b-93d1-546c01680f22/
[INFO    ] SESN0176I: A new session context will be created for application key default_host/0cd89973-56c1-411b-93d1-546c01680f22
[INFO    ] SESN0172I: The session manager is using the Java default SecureRandom implementation for session ID generation.
[INFO    ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at C:\wlp-usr\servers\my-project\logs\state\plugin-cfg.xml.
[AUDIT   ] CWWKZ0001I: Application 0cd89973-56c1-411b-93d1-546c01680f22 started in 12.897 seconds.
[WARNING ] CWWKW1002W: The CDI scope of JAXRS Provider AppParamConverterProvider is javax.enterprise.context.Dependent. Liberty gets the provider instance from CDI.
[WARNING ] CWWKW1002W: The CDI scope of JAXRS Provider ConstraintViolationExceptionMapper is javax.enterprise.context.Dependent. Liberty gets the provider instance from CDI.
[INFO    ] Setting the server's publish address to be /rest/
[INFO    ] SRVE0242I: [0cd89973-56c1-411b-93d1-546c01680f22] [/0cd89973-56c1-411b-93d1-546c01680f22] [br.myPackage.resource.Application]: Initialization successful.
[AUDIT   ] CWWKT0017I: Web application removed (default_host): http://localhost:9080/0cd89973-56c1-411b-93d1-546c01680f22/
[INFO    ] SRVE0253I: [0cd89973-56c1-411b-93d1-546c01680f22] [/0cd89973-56c1-411b-93d1-546c01680f22] [br.myPackage.resource.Application]: Destroy successful.
[AUDIT   ] CWWKZ0009I: The application 0cd89973-56c1-411b-93d1-546c01680f22 has stopped successfully.
[INFO    ] SRVE9103I: A configuration file for a web server plugin was automatically generated for this server at C:\wlp-usr\servers\my-project\logs\state\plugin-cfg.xml.
[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 36.663 s <<< FAILURE! - in br.myPackage.resource.MyResourceIT
[ERROR] br.myPackage.resource.MyResourceIT.testBadRequest  Time elapsed: 0.887 s  <<< FAILURE!
java.lang.AssertionError:
Bad Request
Expected: is <200>
     but: was <400>
        at br.myPackage.resource.MyResourceIT.testBadRequest(MyResourceIT.java:67)

O servidor my-project n?o existe.
[ERROR] Test mechanism :: Could not run @AfterSuite
[INFO]
[INFO] Results:
[INFO]
[ERROR] Failures:
[ERROR]   MyResourceIT.testBadRequest:67 Bad Request
Expected: is <200>
     but: was <400>
[INFO]
[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0
[INFO]
[INFO]
[INFO] --- maven-failsafe-plugin:3.0.0-M5:verify (default-cli) @ my-project ---
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:38 min
[INFO] Finished at: 2021-04-24T14:10:23-03:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-failsafe-plugin:3.0.0-M5:verify (default-cli) on project my-project: There are test failures.
[ERROR]
[ERROR] Please refer to C:\my-project\target\failsafe-reports for the individual test results.
[ERROR] Please refer to dump files (if any exist) [date].dump, [date]-jvmRun[N].dump and [date].dumpstream.
[ERROR] org.apache.maven.surefire.booter.SurefireBooterForkException: There was an error in the forked process
[ERROR] Test mechanism :: Could not run @AfterSuite
[ERROR]         at org.apache.maven.plugin.surefire.booterclient.ForkStarter.fork(ForkStarter.java:733)
[ERROR]         at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:305)
[ERROR]         at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:265)
[ERROR]         at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1314)
[ERROR]         at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:1159)
[ERROR]         at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:932)
[ERROR]         at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137)
[ERROR]         at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:210)
[ERROR]         at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:156)
[ERROR]         at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:148)
[ERROR]         at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117)
[ERROR]         at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81)
[ERROR]         at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:56)
[ERROR]         at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
[ERROR]         at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:305)
[ERROR]         at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192)
[ERROR]         at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105)
[ERROR]         at org.apache.maven.cli.MavenCli.execute(MavenCli.java:957)
[ERROR]         at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:289)
[ERROR]         at org.apache.maven.cli.MavenCli.main(MavenCli.java:193)
[ERROR]         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[ERROR]         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:90)
[ERROR]         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
[ERROR]         at java.lang.reflect.Method.invoke(Method.java:508)
[ERROR]         at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282)
[ERROR]         at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225)
[ERROR]         at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406)
[ERROR]         at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347)
[ERROR]
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException

When usrDir property was unavailable, I had to resort to global server.env file, this way:

pom.xml

  <build>
      <plugin>
        <groupId>io.openliberty.tools</groupId>
        <artifactId>liberty-maven-plugin</artifactId>
        <version>3.3.4</version>
        <configuration>
          <serverName>my-project</serverName>
          <configFile>src/main/liberty/server.xml</configFile>
          <configDirectory>src/main/liberty/local</configDirectory>
          <userDirectory>C:/wlp-usr</userDirectory>
          <libertySettingsFolder>src/main/liberty/local/etc</libertySettingsFolder>
        </configuration>
      </plugin>
  </build>

src/main/liberty/local/etc/server.env

WLP_USER_DIR=C:/wlp-usr/

Using this configuration with liberty-arquillian-managed version 1.0.7 still works fine. The problem seems to have roots in usrDir property in arquillian.xml.

cherylking commented 3 years ago

Thank you for reporting this issue. We will look into it.

cherylking commented 3 years ago

@rslemos I published a 1.0.8-SNAPSHOT for the liberty-arquillian artifacts, and a 1.1.8-SNAPSHOT for the arquillian-liberty-dependencies with the fix for this bug.

cherylking commented 3 years ago

Release 1.0.8 contains this fix.