search

OpenLiberty / ci.maven

Maven plugins for managing Liberty profile servers #devops
Apache License 2.0
130 stars 91 forks source link

Error found when running Liberty dev container mode with Liberty Maven Plugin 3.10.1 on Linux #1802

Closed Ruilin-Ma closed 8 months ago

Ruilin-Ma commented 8 months ago

Error description

The following errors were encountered when attempting to execute mvn liberty:devc -DcontainerRunOpts="-e DB_HOSTNAME=172.17.0.2" -DserverStartTimeout=240 on a Linux VM (RHEL and Ubuntu) using Liberty Maven Plugin version 3.10.1. The environment was configured with IBM Semeru Runtime Open Edition 11.0.22.0 and Maven 3.9.6.

The issue was resolved by downgrading the LMP version to 3.10, and the Liberty dev container mode now runs properly. I'm wondering if any changes are required in the Dockerfile when upgrading LMP to 3.10.1.

Error log for the application working with LMP 3.10.1

mvn liberty:devc -DcontainerRunOpts="-e DB_HOSTNAME=172.17.0.2" -DserverStartTimeout=240
[INFO] Scanning for projects...
[INFO] 
[INFO] -------------< io.openliberty.guides:guide-testcontainers >-------------
[INFO] Building guide-testcontainers 1.0-SNAPSHOT
[INFO]   from pom.xml
[INFO] --------------------------------[ war ]---------------------------------
[INFO] 
[INFO] --- liberty:3.10.1:devc (default-cli) @ guide-testcontainers ---
[INFO] The recompileDependencies parameter is set to "false". On a file change only the affected classes will be recompiled.
[INFO] Running maven-resources-plugin:resources
[INFO] Copying 1 resource from src/main/resources to target/classes
[INFO] Running maven-compiler-plugin:compile on /root/testing/guide-testcontainers/start/pom.xml
[INFO] Nothing to compile - all classes are up to date
[INFO] Running maven-resources-plugin:testResources
[INFO] Copying 1 resource from src/test/resources to target/test-classes
[INFO] Running maven-compiler-plugin:testCompile on /root/testing/guide-testcontainers/start/pom.xml
[INFO] Nothing to compile - all classes are up to date
[INFO] Running liberty:deploy
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer
[INFO] CWWKM2144I: Update server configuration file server.xml from /root/testing/guide-testcontainers/start/src/main/liberty/config/server.xml.
[INFO] Adding transitive dependency with scope: provided and GAV: org.checkerframework:checker-qual:3.42.0
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file postgresql-42.7.2.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/postgresql-42.7.2.jar.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file checker-qual-3.42.0.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/checker-qual-3.42.0.jar.
[INFO] CWWKM2185I: The liberty-maven-plugin configuration parameter "appsDirectory" value defaults to "apps".
[INFO] Application configuration is found in server.xml : inventory.war
[INFO] CWWKM2160I: Installing application inventory.war.xml.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer
[INFO] CWWKM2144I: Update server configuration file server.xml from /root/testing/guide-testcontainers/start/src/main/liberty/config/server.xml.
[INFO] Adding transitive dependency with scope: provided and GAV: org.checkerframework:checker-qual:3.42.0
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file postgresql-42.7.2.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/postgresql-42.7.2.jar.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file checker-qual-3.42.0.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/checker-qual-3.42.0.jar.
[INFO] CWWKM2185I: The liberty-maven-plugin configuration parameter "appsDirectory" value defaults to "apps".
[WARNING] The Containerfile line 'COPY --chown=1001:0  --from=staging /work/postgresql-*.jar /opt/ol/wlp/usr/shared/resources/' will not be able to be hot deployed to the dev mode container. Dev mode does not currently support hot deployment with multi-stage COPY commands.
[INFO] Building container image...
[INFO] Container command: docker build --pull -f /root/testing/guide-testcontainers/start/target/.libertyDevc/tempContainerfile11521985672516852042 -t guide-testcontainers-dev-mode /root/testing/guide-testcontainers/start
[INFO] The RUN features.sh command is detected in the Containerfile and extra time may be necessary when installing features.
[ERROR] #0 building with "default" instance using docker driver
[ERROR] 
[ERROR] #1 [internal] load .dockerignore
[ERROR] #1 transferring context: 105B done
[ERROR] #1 DONE 0.0s
[ERROR] 
[ERROR] #2 [internal] load build definition from tempContainerfile11521985672516852042
[ERROR] #2 transferring dockerfile: 1.07kB done
[ERROR] #2 DONE 0.1s
[ERROR] 
[ERROR] #3 [auth] library/maven:pull token for registry-1.docker.io
[ERROR] #3 DONE 0.0s
[ERROR] 
[ERROR] #4 [internal] load metadata for docker.io/library/maven:3.9.6
[ERROR] #4 ...
[ERROR] 
[ERROR] #5 [internal] load metadata for icr.io/appcafe/open-liberty:kernel-slim-java11-openj9-ubi
[ERROR] #5 DONE 0.5s
[ERROR] 
[ERROR] #4 [internal] load metadata for docker.io/library/maven:3.9.6
[ERROR] #4 DONE 0.6s
[ERROR] 
[ERROR] #6 [staging 1/3] FROM docker.io/library/maven:3.9.6@sha256:873dec32acf4fbb756a71c8aedeb0a8c8a77579e41728f0c4cda747a339a7d2d
[ERROR] #6 DONE 0.0s
[ERROR] 
[ERROR] #7 [stage-1 1/5] FROM icr.io/appcafe/open-liberty:kernel-slim-java11-openj9-ubi@sha256:7d617cd32ac7a7e6d8df9256d1e027e8c23cb7238c63234f85919035379ed22c
[ERROR] #7 DONE 0.0s
[ERROR] 
[ERROR] #8 [internal] load build context
[ERROR] #8 transferring context: 186B done
[ERROR] #8 DONE 0.0s
[ERROR] 
[ERROR] #9 [stage-1 3/5] RUN features.sh
[ERROR] #9 CACHED
[ERROR] 
[ERROR] #10 [stage-1 4/5] COPY --chown=1001:0  --from=staging /work/postgresql-*.jar /opt/ol/wlp/usr/shared/resources/
[ERROR] #10 CACHED
[ERROR] 
[ERROR] #11 [stage-1 2/5] COPY --chown=1001:0 src/main/liberty/config/ /config/
[ERROR] #11 CACHED
[ERROR] 
[ERROR] #12 [staging 3/3] RUN mvn dependency:copy -Dartifact=org.postgresql:postgresql:42.7.2 -DoutputDirectory=/work
[ERROR] #12 CACHED
[ERROR] 
[ERROR] #13 [staging 2/3] WORKDIR /work
[ERROR] #13 CACHED
[ERROR] 
[ERROR] #14 [stage-1 5/5] RUN configure.sh
[ERROR] #14 CACHED
[ERROR] 
[ERROR] #15 exporting to image
[ERROR] #15 exporting layers done
[ERROR] #15 writing image sha256:8d191fe92fd8b69e3cff67f9ffa4b2f623dc04bb0172fe3c64e79394ad9c90d2 done
[ERROR] #15 naming to docker.io/library/guide-testcontainers-dev-mode done
[ERROR] #15 DONE 0.0s
[INFO] Completed building container image.
[INFO] Starting container...
[INFO] Container command: docker run --rm -p 9080:9080 -p 9443:9443 -p 7777:7777 -e WLP_DEBUG_SUSPEND=n -e WLP_DEBUG_ADDRESS=7777 -e WLP_DEBUG_REMOTE=y -v /root/testing/guide-testcontainers/start/target/.libertyDevc/apps:/config/apps -v /root/testing/guide-testcontainers/start/target/.libertyDevc/dropins:/config/dropins -v /root/testing/guide-testcontainers/start:/devmode -v /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer/logs:/logs -v /root/.m2/repository:/devmode-maven-cache --user 0  --name liberty-dev -e DB_HOSTNAME=172.17.0.2 guide-testcontainers-dev-mode server debug defaultServer -- --io.openliberty.tools.projectRoot=/devmode
[ERROR] docker: Error response from daemon: unable to find user 0 : no matching entries in passwd file.
[ERROR] An error occurred while running the container: docker: Error response from daemon: unable to find user 0 : no matching entries in passwd file. RC=125
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  4.179 s
[INFO] Finished at: 2024-03-06T13:44:22-08:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal io.openliberty.tools:liberty-maven-plugin:3.10.1:devc (default-cli) on project guide-testcontainers: Error starting the server in dev mode.: An error occurred while running the container: docker: Error response from daemon: unable to find user 0 : no matching entries in passwd file. RC=125 -> [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

Terminal log for application working with LMP 3.10 (Working scenario)

 mvn liberty:devc -DcontainerRunOpts="-e DB_HOSTNAME=172.17.0.2" -DserverStartTimeout=240
[INFO] Scanning for projects...
[INFO] 
[INFO] -------------< io.openliberty.guides:guide-testcontainers >-------------
[INFO] Building guide-testcontainers 1.0-SNAPSHOT
[INFO]   from pom.xml
[INFO] --------------------------------[ war ]---------------------------------
[INFO] 
[INFO] --- liberty:3.10:devc (default-cli) @ guide-testcontainers ---
[INFO] The recompileDependencies parameter is set to "false". On a file change only the affected classes will be recompiled.
[INFO] Running maven-resources-plugin:resources
[INFO] Copying 1 resource from src/main/resources to target/classes
[INFO] Running maven-compiler-plugin:compile on /root/testing/guide-testcontainers/start/pom.xml
[INFO] Nothing to compile - all classes are up to date
[INFO] Running maven-resources-plugin:testResources
[INFO] Copying 1 resource from src/test/resources to target/test-classes
[INFO] Running maven-compiler-plugin:testCompile on /root/testing/guide-testcontainers/start/pom.xml
[INFO] Nothing to compile - all classes are up to date
[INFO] Running liberty:deploy
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer
[WARNING] /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer/configDropins/overrides/liberty-plugin-variable-config.xml file deleted before processing plugin configuration.
[INFO] CWWKM2144I: Update server configuration file server.xml from /root/testing/guide-testcontainers/start/src/main/liberty/config/server.xml.
[INFO] Adding transitive dependency with scope: provided and GAV: org.checkerframework:checker-qual:3.42.0
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file postgresql-42.7.2.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/postgresql-42.7.2.jar.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file checker-qual-3.42.0.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/checker-qual-3.42.0.jar.
[INFO] CWWKM2185I: The liberty-maven-plugin configuration parameter "appsDirectory" value defaults to "apps".
[INFO] Application configuration is found in server.xml : inventory.war
[INFO] CWWKM2160I: Installing application inventory.war.xml.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer
[WARNING] /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer/configDropins/overrides/liberty-plugin-variable-config.xml file deleted before processing plugin configuration.
[INFO] CWWKM2144I: Update server configuration file server.xml from /root/testing/guide-testcontainers/start/src/main/liberty/config/server.xml.
[INFO] Adding transitive dependency with scope: provided and GAV: org.checkerframework:checker-qual:3.42.0
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file postgresql-42.7.2.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/postgresql-42.7.2.jar.
[INFO] Copying 1 file to /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources
[INFO] copyDependencies copied file checker-qual-3.42.0.jar to location /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/shared/resources/checker-qual-3.42.0.jar.
[WARNING] The Containerfile line 'COPY --chown=1001:0  --from=staging /work/postgresql-*.jar /opt/ol/wlp/usr/shared/resources/' will not be able to be hot deployed to the dev mode container. Dev mode does not currently support hot deployment with multi-stage COPY commands.
[INFO] Building container image...
[INFO] docker  build --pull -f /root/testing/guide-testcontainers/start/target/.libertyDevc/tempContainerfile1056651726895928509 -t guide-testcontainers-dev-mode /root/testing/guide-testcontainers/start
[INFO] The RUN features.sh command is detected in the Containerfile and extra time may be necessary when installing features.
[ERROR] #0 building with "default" instance using docker driver
[ERROR] 
[ERROR] #1 [internal] load build definition from tempContainerfile1056651726895928509
[ERROR] #1 transferring dockerfile: 1.07kB done
[ERROR] #1 DONE 0.0s
[ERROR] 
[ERROR] #2 [internal] load .dockerignore
[ERROR] #2 transferring context: 105B done
[ERROR] #2 DONE 0.1s
[ERROR] 
[ERROR] #3 [internal] load metadata for docker.io/library/maven:3.9.6
[ERROR] #3 ...
[ERROR] 
[ERROR] #4 [auth] library/maven:pull token for registry-1.docker.io
[ERROR] #4 DONE 0.0s
[ERROR] 
[ERROR] #5 [internal] load metadata for icr.io/appcafe/open-liberty:kernel-slim-java11-openj9-ubi
[ERROR] #5 DONE 0.5s
[ERROR] 
[ERROR] #3 [internal] load metadata for docker.io/library/maven:3.9.6
[ERROR] #3 DONE 0.6s
[ERROR] 
[ERROR] #6 [stage-1 1/5] FROM icr.io/appcafe/open-liberty:kernel-slim-java11-openj9-ubi@sha256:7d617cd32ac7a7e6d8df9256d1e027e8c23cb7238c63234f85919035379ed22c
[ERROR] #6 DONE 0.0s
[ERROR] 
[ERROR] #7 [staging 1/3] FROM docker.io/library/maven:3.9.6@sha256:873dec32acf4fbb756a71c8aedeb0a8c8a77579e41728f0c4cda747a339a7d2d
[ERROR] #7 DONE 0.0s
[ERROR] 
[ERROR] #8 [internal] load build context
[ERROR] #8 transferring context: 186B done
[ERROR] #8 DONE 0.0s
[ERROR] 
[ERROR] #9 [staging 3/3] RUN mvn dependency:copy -Dartifact=org.postgresql:postgresql:42.7.2 -DoutputDirectory=/work
[ERROR] #9 CACHED
[ERROR] 
[ERROR] #10 [stage-1 4/5] COPY --chown=1001:0  --from=staging /work/postgresql-*.jar /opt/ol/wlp/usr/shared/resources/
[ERROR] #10 CACHED
[ERROR] 
[ERROR] #11 [staging 2/3] WORKDIR /work
[ERROR] #11 CACHED
[ERROR] 
[ERROR] #12 [stage-1 2/5] COPY --chown=1001:0 src/main/liberty/config/ /config/
[ERROR] #12 CACHED
[ERROR] 
[ERROR] #13 [stage-1 3/5] RUN features.sh
[ERROR] #13 CACHED
[ERROR] 
[ERROR] #14 [stage-1 5/5] RUN configure.sh
[ERROR] #14 CACHED
[ERROR] 
[ERROR] #15 exporting to image
[ERROR] #15 exporting layers done
[ERROR] #15 writing image sha256:8d191fe92fd8b69e3cff67f9ffa4b2f623dc04bb0172fe3c64e79394ad9c90d2 done
[ERROR] #15 naming to docker.io/library/guide-testcontainers-dev-mode done
[ERROR] #15 DONE 0.0s
[INFO] Completed building container image.
[INFO] Starting container...
[INFO] docker run --rm -p 9080:9080 -p 9443:9443 -p 7777:7777 -e WLP_DEBUG_SUSPEND=n -e WLP_DEBUG_ADDRESS=7777 -e WLP_DEBUG_REMOTE=y -v /root/testing/guide-testcontainers/start/target/.libertyDevc/apps:/config/apps -v /root/testing/guide-testcontainers/start/target/.libertyDevc/dropins:/config/dropins -v /root/testing/guide-testcontainers/start:/devmode -v /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer/logs:/logs -v /root/.m2/repository:/devmode-maven-cache --user 0  --name liberty-dev -e DB_HOSTNAME=172.17.0.2 guide-testcontainers-dev-mode server debug defaultServer -- --io.openliberty.tools.projectRoot=/devmode
[INFO] 
[INFO] Listening for transport dt_socket at address: 7777
[INFO] Launching defaultServer (Open Liberty 24.0.0.2/wlp-1.0.86.cl240220240212-1928) on Eclipse OpenJ9 VM, version 11.0.22+7 (en_US)
[INFO]  Parameters: [--io.openliberty.tools.projectRoot=/devmode]
[INFO] [AUDIT   ] CWWKE0001I: The server defaultServer has been launched.
[INFO] CWWKM2010I: Searching for CWWKF0011I: in /root/testing/guide-testcontainers/start/target/liberty/wlp/usr/servers/defaultServer/logs/messages.log. This search will timeout after 240 seconds.
[INFO] [AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/defaultServer/configDropins/defaults/keystore.xml
[INFO] [AUDIT   ] CWWKG0093A: Processing configuration drop-ins resource: /opt/ol/wlp/usr/servers/defaultServer/configDropins/defaults/open-default-port.xml
[INFO] [AUDIT   ] CWWKG0102I: Found conflicting settings for defaultKeyStore instance of keyStore configuration.
[INFO]   Property password has conflicting values:
[INFO]     Secure value is set in file:/opt/ol/wlp/usr/servers/defaultServer/configDropins/defaults/keystore.xml.
[INFO]     Secure value is set in file:/opt/ol/wlp/usr/servers/defaultServer/server.xml.
[INFO]   Property password will be set to the value defined in file:/opt/ol/wlp/usr/servers/defaultServer/server.xml.
[INFO] 
[INFO] [AUDIT   ] CWWKZ0058I: Monitoring dropins for applications.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://942f093f1df1:9080/health/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://942f093f1df1:9080/openapi/
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://942f093f1df1:9080/openapi/ui/
[INFO] [AUDIT   ] CWPKI0803A: SSL certificate created in 2.503 seconds. SSL key file: /opt/ol/wlp/output/defaultServer/resources/security/key.p12
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://942f093f1df1:9080/inventory/
[INFO] [AUDIT   ] CWWKZ0001I: Application inventory started in 9.286 seconds.
[INFO] [AUDIT   ] CWWKF0012I: The server installed the following features: [cdi-4.0, jdbc-4.2, jndi-1.0, json-1.0, jsonb-3.0, jsonp-2.1, monitor-1.0, mpConfig-3.0, mpHealth-4.0, mpOpenAPI-3.1, persistence-3.1, persistenceContainer-3.1, restfulWS-3.1, restfulWSClient-3.1, ssl-1.0, transportSecurity-1.0].
[INFO] [AUDIT   ] CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 16.219 seconds.
[INFO] CWWKM2015I: Match number: 1 is [3/6/24, 23:22:07:533 UTC] 00000034 com.ibm.ws.kernel.feature.internal.FeatureManager            A CWWKF0011I: The defaultServer server is ready to run a smarter planet. The defaultServer server started in 16.219 seconds..
[INFO] ************************************************************************
[INFO] *    Liberty is running in dev mode.
[INFO] *        Automatic generation of features: [ Off ]
[INFO] *        h - see the help menu for available actions, type 'h' and press Enter.
[INFO] *        q - stop the server and quit dev mode, press Ctrl-C or type 'q' and press Enter.
[INFO] *        
[INFO] *    Liberty container port information:
[INFO] *        Internal container HTTP port [ 9080 ] is mapped to container host port [ 9080 ]
[INFO] *        Internal container HTTPS port [ 9443 ] is mapped to container host port [ 9443 ]
[INFO] *        Liberty debug port mapped to container host port: [ 7777 ]
[INFO] *        
[INFO] *    Container network information:
[INFO] *        Container name: [ liberty-dev ]
[INFO] *        IP address [ 172.17.0.3 ] on container network [ bridge ]
[INFO] ************************************************************************
[INFO] Source compilation was successful.
[INFO] [AUDIT   ] CWWKT0017I: Web application removed (default_host): http://942f093f1df1:9080/inventory/
[INFO] [AUDIT   ] CWWKZ0009I: The application inventory has stopped successfully.
[INFO] [AUDIT   ] CWWKT0016I: Web application available (default_host): http://942f093f1df1:9080/inventory/
[INFO] [AUDIT   ] CWWKZ0003I: The application inventory updated in 0.802 seconds.
gkwan-ibm commented 8 months ago

even simply running mvn liberty:devc has this problem

cherylking commented 8 months ago

even simply running mvn liberty:devc has this problem

Yes, but only on Linux. It is related to this PR which changed how the docker commands are built (ironically in order to handle embedded spaces within a parameter/option). It seems the user that is returned by a LInux OS command has a trailing space and therefore gets passed on the docker command as --user 0. This causes the docker command to fail.