AppCDS Archive Generation with quarkus-container-image-jib causes a timestamp mismatch

[davidreis97]

Describe the bug

When creating an AppCDS Archive with container image generation through the quarkus-container-image-jib extension, the following Docker command gets executed:

docker run -v /Users/my-user/repos/my-service/target:/tmp/quarkus:z -w /tmp/quarkus/quarkus-app --rm registry.access.redhat.com/ubi8/openjdk-21-runtime:1.18 java -XX:ArchiveClassesAtExit=app-cds.jsa -Dquarkus.appcds.generate=true -jar quarkus-run.jar

This command mounts the /target folder as a volume, which contains the library folders /quarkus-app/lib/boot and /quarkus-app/lib/main. This means that the AppCDS archive will be generated with the .jar files that are inside these two folders.

The issue is that after the AppCDS archive generation process, in the quarkus-container-image-jib image generation, the .jar files inside the /quarkus-app/lib/boot and /quarkus-app/lib/main folders are copied into the image in a way that causes their timestamp to change. See quarkusio/quarkus/extensions/container-image/container-image-jib/deployment/src/main/java/io/quarkus/container/image/jib/deployment/JibProcessor.java to see how this is done.

As an example, when building the AppCDS, these are the files inside the /lib/boot folder:

And these are the files inside the final container:

As you can see, the timestamps are different, which causes the error when CDS tries to load up the archive:

Picked up JAVA_TOOL_OPTIONS: -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=*:5005 -Dio.netty.leakDetection.level=paranoid -Xlog:class+path=info

[0.002s][info][class,path] bootstrap loader class path=/usr/lib/jvm/java-21-openjdk-21.0.1.0.12-3.el8.x86_64/lib/modules
[0.008s][info][class,path] Expecting BOOT path=/usr/lib/jvm/java-21-openjdk-21.0.1.0.12-3.el8.x86_64/lib/modules
[0.008s][info][class,path] Expecting -Djava.class.path=
[0.008s][info][class,path] checking shared classpath entry: /usr/lib/jvm/java-21-openjdk-21.0.1.0.12-3.el8.x86_64/lib/modules
[0.008s][info][class,path] ok
[0.022s][info][class,path] Expecting BOOT path=/usr/lib/jvm/java-21-openjdk-21.0.1.0.12-3.el8.x86_64/lib/modules
[0.022s][info][class,path] Expecting -Djava.class.path=quarkus-run.jar:lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar:lib/boot/io.smallrye.common.smallrye-common-os-2.1.2.jar:lib/boot/io.quarkus.quarkus-development-mode-spi-3.6.3.jar:lib/boot/io.quarkus.quarkus-bootstrap-runner-3.6.3.jar:lib/boot/io.smallrye.common.smallrye-common-io-2.1.2.jar:lib/boot/io.quarkus.quarkus-vertx-latebound-mdc-provider-3.6.3.jar:lib/boot/io.github.crac.org-crac-0.1.3.jar:lib/boot/org.jboss.logmanager.jboss-logmanager-3.0.2.Final.jar:lib/boot/io.smallrye.common.smallrye-common-constraint-2.1.2.jar:lib/boot/io.smallrye.common.smallrye-common-cpu-2.1.2.jar:lib/boot/io.smallrye.common.smallrye-common-expression-2.1.2.jar:lib/boot/io.smallrye.common.smallrye-common-function-2.1.2.jar:lib/boot/io.smallrye.common.smallrye-common-net-2.1.2.jar:lib/boot/io.smallrye.common.smallrye-common-ref-2.1.2.jar
[0.022s][info][class,path] checking shared classpath entry: /usr/lib/jvm/java-21-openjdk-21.0.1.0.12-3.el8.x86_64/lib/modules
[0.022s][info][class,path] ok
[0.022s][info][class,path] checking shared classpath entry: quarkus-run.jar
[0.022s][info][class,path] ok
[0.022s][info][class,path] checking shared classpath entry: lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar
[0.022s][warning][cds       ] A jar file is not the one used while building the shared archive file: lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar
[0.023s][warning][cds       ] A jar file is not the one used while building the shared archive file: lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar
[0.023s][warning][cds       ] lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar timestamp has changed.
[0.024s][warning][cds,dynamic] Unable to use shared archive. The top archive failed to load: app-cds.jsa

I would suggest changing the layer creation in the quarkus-container-image-jib to ensure that the timestamps are not changed. A common solution for this is to tar the files before moving them to a layer in the image.

Expected behavior

All the libraries that are used when generating the AppCDS archive must be exactly the same as the ones used when creating the image.

Actual behavior

No response

How to Reproduce?

No response

Output of uname -a or ver

Darwin <computer_name> 23.2.0 Darwin Kernel Version 23.2.0: Wed Nov 15 21:53:18 PST 2023; root:xnu-10002.61.3~2/RELEASE_ARM64_T6000 arm64 arm Darwin

Output of java -version

openjdk version "21.0.1" 2023-10-17 OpenJDK Runtime Environment (build 21.0.1+12-29) OpenJDK 64-Bit Server VM (build 21.0.1+12-29, mixed mode, sharing)

Quarkus version or git rev

Quarkus 3.6.3

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.8.6

Additional information

No response

[quarkus-bot[bot]]

/cc @geoand (jib)

[geoand]

Thanks for the report!

As you seem to have done an analysis on the source code, would you be interested in providing a fix?

[davidreis97]

I just compiled the Quarkus main branch and used it to generate the image and could not replicate this issue as the timestamp was properly carried over to the final image. I did this twice. I then went back to Quarkus 3.6.4 and the issue happened again.

So I'd say this has been fixed, although I do not see any new commits in the relevant sections of code - only #37647 which at first glance I'd say is unrelated to this issue I was having, but maybe it is related? In any case, it seems like the next version of Quarkus should fix this for us.

[geoand]

Thanks for checking!

[Pierre-Lemaigre]

Hello, I checked with quarkus version 3.7.1 released yesterday, it is failling with this:

[0.012s][warning][cds] A jar file is not the one used while building the shared archive file: lib/boot/io.quarkus.quarkus-bootstrap-runner-3.7.1.jar
[0.012s][warning][cds] A jar file is not the one used while building the shared archive file: lib/boot/io.quarkus.quarkus-bootstrap-runner-3.7.1.jar
[0.012s][warning][cds] lib/boot/io.quarkus.quarkus-bootstrap-runner-3.7.1.jar timestamp has changed.
[0.013s][warning][cds,dynamic] Unable to use shared archive. The top archive failed to load: app-cds.jsa
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
11:18:24 INFO   [co.li.ve.do.wo.OdtTemplateManagerWorker] Startup Event io.quarkus.runtime.StartupEvent@41f4fe5 -> Created template file at path: /home/jboss/template.odt
11:18:24 INFO   [io.quarkus] vectorstodoc 0.0.1-alpha on JVM (powered by Quarkus 3.7.1) started in 0.817s. Listening on: http://0.0.0.0:8080
11:18:24 INFO   [io.quarkus] Profile prod activated. 
11:18:24 INFO   [io.quarkus] Installed features: [cdi, resteasy-reactive, resteasy-reactive-jackson, smallrye-context-propagation, smallrye-openapi, vertx]

I don't know if it is my particular setup that cause the fails, i'm happy to help if you need further infos.

[geoand]

I'll check again soon

[Pierre-Lemaigre]

Thank you! :ok_hand:

[geoand]

I could not reproduce the problem this time either

[davidreis97]

It's weird, I had the same issue with version 3.6.x, but when I switched to the main branch, the problem disappeared. What's really strange is that I didn't see any code changes between 3.6.x and the main branch that could explain this. Makes me think there might be a sneaky bug hiding somewhere.

[Pierre-Lemaigre]

Re-tested with 3.7.2. It is weird, i have two project, one is fine, the other is not working. The one not working is on java 21, maybe this or the fact that I use a custom image without sha 256 is the root cause. I will investigate more.

[Pierre-Lemaigre]

I think I found the bug. or i'm not sure if it is a bug or the normal behaviour. Basically if I have anything else than

package com.acme;

import io.quarkus.runtime.Quarkus;
import io.quarkus.runtime.QuarkusApplication;
import io.quarkus.runtime.annotations.QuarkusMain;

@QuarkusMain
public class Main {
    public static void main(String... args) {
        Quarkus.run(MyApp.class, args);
    }

    public static class MyApp implements QuarkusApplication {

        @Override
        public int run(String... args) throws Exception {
            System.out.println("Do startup logic here");
            Quarkus.waitForExit();
            return 0;
        }
    }
}

This mean: Basic autogenerated quarkusmain or defined quarkusmain but without the public static class that extend quarkusapplication, then it does not work. This is the only difference that make my app working with appcds. Again i'm not sure if this is the intended behaviour or not, or just a bug because of others dependencies messing with appcds.

[geoand]

Do you mind sharing the application that you came up with that reproduces the problem?

Thanks

[davidreis97]

Just to note, I also got this error again on 3.7.2, even though just a few weeks ago I was able to make it work with the code on the main branch. Perhaps this issue should be reopened?

Picked up JAVA_TOOL_OPTIONS: -Xlog:cds=debug

[0.022s][info][cds] trying to map /usr/lib/jvm/java-17-openjdk-17.0.10.0.7-2.el8.x86_64/lib/server/classes.jsa
[0.022s][info][cds] Opened archive /usr/lib/jvm/java-17-openjdk-17.0.10.0.7-2.el8.x86_64/lib/server/classes.jsa.
[0.022s][info][cds] Archive was created with UseCompressedOops = 1, UseCompressedClassPointers = 1
[0.022s][info][cds] Core region alignment: 4096
[0.022s][info][cds] trying to map app-cds.jsa
[0.022s][info][cds] Opened archive app-cds.jsa.
[0.022s][info][cds] Archive was created with UseCompressedOops = 1, UseCompressedClassPointers = 1
[0.022s][info][cds] ArchiveRelocationMode == 1: always map archive(s) at an alternative address
[0.022s][info][cds] Try to map archive(s) at an alternative address
[0.022s][info][cds] Reserved archive_space_rs [0x00007fb9d1000000 - 0x00007fb9d4000000] (50331648) bytes
[0.022s][info][cds] Reserved class_space_rs   [0x00007fb9d4000000 - 0x00007fba14000000] (1073741824) bytes
[0.022s][info][cds] Mapped static  region #0 at base 0x00007fb9d1000000 top 0x00007fb9d1455000 (ReadWrite)
[0.022s][info][cds] Mapped static  region #1 at base 0x00007fb9d1455000 top 0x00007fb9d1bc9000 (ReadOnly)
[0.022s][info][cds] Mapped static  region #2 at base 0x00007fba3446b000 top 0x00007fba344a2000 (Bitmap)
[0.060s][info][cds] Mapped dynamic region #0 at base 0x00007fb9d1bc9000 top 0x00007fb9d24ef000 (ReadWrite)
[0.060s][info][cds] Mapped dynamic region #1 at base 0x00007fb9d24ef000 top 0x00007fb9d3230000 (ReadOnly)
[0.060s][info][cds] Mapped dynamic region #2 at base 0x00007fba313fb000 top 0x00007fba31455000 (Bitmap)
[0.069s][info][cds] UseSharedSpaces: A jar file is not the one used while building the shared archive file: lib/boot/org.jboss.logging.jboss-logging-3.5.3.Final.jar
[0.069s][info][cds] Unmapping region #0 at base 0x00007fb9d1bc9000 (ReadWrite)
[0.069s][info][cds] Unmapping region #1 at base 0x00007fb9d24ef000 (ReadOnly)
[0.070s][info][cds] Unmapping region #2 at base 0x00007fba313fb000 (Bitmap)
[0.070s][warning][cds,dynamic] Unable to use shared archive. The top archive failed to load: app-cds.jsa

[geoand]

Perhaps this issue should be reopened?

Sure

[Pierre-Lemaigre]

Hello, I was trying to reproduce the bug with different versions. Turns out as of 3.8.2 the bug is no longer here, so for my pov, the issue can be closed. Maybe someone else can comment or follow up on this?

[geoand]

Thanks for checking!

I'll close this and if someone comments it's still an issue, we can reopen