[GR-40565] Watchdog detects no activity during classpath scanning and kills the process

[barry-gq]

Environment：
macos

openjdk version "11.0.16" 2022-07-19
OpenJDK Runtime Environment GraalVM CE 22.2.0 (build 11.0.16+8-jvmci-22.2-b06)
OpenJDK 64-Bit Server VM GraalVM CE 22.2.0 (build 11.0.16+8-jvmci-22.2-b06, mixed mode, sharing)

Q：I wrote a HellWorld test class for local compilation and testing, but the following error occurred

ps：I used the graalVM 21+ version at first, and this problem also occurred at that time. Later, I found a similar problem in the issue（#2283, and the description has been solved. Later, I upgraded the graalVM version, but the problem still exists.

cmd：native-image HelloWorld

WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
GraalVM Native Image: Generating 'helloworld' (executable)...
[1/7] Initializing... (46.3s @ 0.10GB)
Version info: 'GraalVM 22.2.0 Java 11 CE'
Java version info: '11.0.16+8-jvmci-22.2-b06'
C compiler: cc (apple, x86_64, 13.1.6)
Garbage collector: Serial GC

=== Image generator watchdog detected no activity. This can be a sign of a deadlock during image building. Dumping all stack traces. Current time: Wed Aug 17 14:22:27 CST 2022
"main" Id=1 in RUNNABLE
at java.base@11.0.16/java.nio.file.Files$2.hasNext(Files.java:3708)
at java.base@11.0.16/java.util.Iterator.forEachRemaining(Iterator.java:132)
at java.base@11.0.16/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
at java.base@11.0.16/java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.ClassLoaderSupportImpl.scanDirectory(ClassLoaderSupportImpl.java:168)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.ClassLoaderSupportImpl.collectResources(ClassLoaderSupportImpl.java:109)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.ResourcesFeature.duringAnalysis(ResourcesFeature.java:266)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.lambda$runPointsToAnalysis$10(NativeImageGenerator.java:734)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator$$Lambda$827/0x00000007c0e76040.accept(Unknown Source)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.FeatureHandler.forEachFeature(FeatureHandler.java:78)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.lambda$runPointsToAnalysis$11(NativeImageGenerator.java:734)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator$$Lambda$521/0x00000007c0d88c40.apply(Unknown Source)
at app/org.graalvm.nativeimage.pointsto/com.oracle.graal.pointsto.PointsToAnalysis.runAnalysis(PointsToAnalysis.java:755)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:731)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:564)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.run(NativeImageGenerator.java:521)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.buildImage(NativeImageGeneratorRunner.java:407)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.build(NativeImageGeneratorRunner.java:585)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGeneratorRunner.main(NativeImageGeneratorRunner.java:128)

"Reference Handler" Id=2 in RUNNABLE
at java.base@11.0.16/java.lang.ref.Reference.waitForReferencePendingList(Native Method)
at java.base@11.0.16/java.lang.ref.Reference.processPendingReferences(Reference.java:241)
at java.base@11.0.16/java.lang.ref.Reference$ReferenceHandler.run(Reference.java:213)

"Finalizer" Id=3 in WAITING on lock=java.lang.ref.ReferenceQueue$Lock@4dd3b6c7
at java.base@11.0.16/java.lang.Object.wait(Native Method)
at java.base@11.0.16/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
at java.base@11.0.16/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176)
at java.base@11.0.16/java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:170)

"Signal Dispatcher" Id=4 in RUNNABLE

"JVMCI-native CompilerThread0" Id=6 in RUNNABLE

"Common-Cleaner" Id=9 in TIMED_WAITING on lock=java.lang.ref.ReferenceQueue$Lock@4e2fab8e
at java.base@11.0.16/java.lang.Object.wait(Native Method)
at java.base@11.0.16/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
at java.base@11.0.16/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
at java.base@11.0.16/java.lang.Thread.run(Thread.java:829)
at java.base@11.0.16/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:161)

"Thread-1" Id=19 in RUNNABLE
at java.management@11.0.16/sun.management.ThreadImpl.dumpThreads0(Native Method)
at java.management@11.0.16/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:521)
at java.management@11.0.16/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:509)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.DeadlockWatchdog.threadDump(DeadlockWatchdog.java:113)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.DeadlockWatchdog.watchdogThread(DeadlockWatchdog.java:80)
at app/org.graalvm.nativeimage.builder/com.oracle.svm.hosted.DeadlockWatchdog$$Lambda$179/0x00000007c0287440.run(Unknown Source)
at java.base@11.0.16/java.lang.Thread.run(Thread.java:829)

"ForkJoinPool-4-worker-3" Id=25 in WAITING on lock=java.util.concurrent.ForkJoinPool@350cf2c7
at java.base@11.0.16/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.16/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
at java.base@11.0.16/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1628)
at java.base@11.0.16/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

"ForkJoinPool-2-worker-13" Id=38 in WAITING on lock=java.util.concurrent.ForkJoinPool@1f354e7c
at java.base@11.0.16/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@11.0.16/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
at java.base@11.0.16/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1628)
at java.base@11.0.16/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)

=== Memory statistics (in MB):
=== Used heap size: 12376
=== Free heap size: 3632
=== Maximum heap size: 12376
=== Image generator watchdog is aborting image generation. To configure the watchdog, use the options -H:DeadlockWatchdogInterval=10 and -H:+DeadlockWatchdogExitOnTimeout
Error: Image build request failed with exit status 1

how do I fix it

[vjovanov]

What was your working directory and how many subfolders does it contain?

Native Image scans all the folders in the current working directory to find classes that should be on the classpath. If this folder is large, especially on network drives, this can take some time.

This behavior is going to change in the future, but it requires significant changes to the image builder.

[barry-gq]

What was your working directory and how many subfolders does it contain?

Native Image scans all the folders in the current working directory to find classes that should be on the classpath. If this folder is large, especially on network drives, this can take some time.

This behavior is going to change in the future, but it requires significant changes to the image builder.

I checked it just now, there are many files under my folder, and then I created a new empty folder for testing and found that it works, thank you for your help

[barry-gq]

What was your working directory and how many subfolders does it contain?
Native Image scans all the folders in the current working directory to find classes that should be on the classpath. If this folder is large, especially on network drives, this can take some time.
This behavior is going to change in the future, but it requires significant changes to the image builder.

I checked it just now, there are many files under my folder, and then I created a new empty folder for testing and found that it works, thank you for your help

By the way, what should I do if my project file is very large and there are too many, I can only wait for you to optimize it?

[vjovanov]

How many files are in question? This should only happen if you pull in large parts of your file system.

[vjovanov]

We certainly need to handle this better:

1. We need to reset the watchdog after every 1000 files or so.
2. We need to inform the users about this issue (and explain how to fix it) after we surpass a certain amount of time (e.g., 20s).

[jigneshkhatri]

Is there any solution for this issue, if we have large amount of Java classes? I have mid-sized Micronaut project but it fails with same exception as mentioned in this thread while trying to build native image, and I have no idea how to build it now.

[vjovanov]

If it is a regular project, the classpath scanning should not be a problem. Can you share a reproducer?

[jigneshkhatri]

Thanks for the very quick response. It is a Micronaut project for AWS Lambda. Unfortunately I would not be able to share the source code as it is confidential. But is the above error related to many classes there on the classpath (in the folder where we are building it)?

Below are the dependencies in my build.gradle if that helps:

dependencies {
    annotationProcessor('io.micronaut:micronaut-inject-java')
    annotationProcessor("io.micronaut.data:micronaut-data-processor")
    annotationProcessor("io.micronaut:micronaut-http-validation")
    implementation("io.micronaut:micronaut-http-client")
    implementation("io.micronaut:micronaut-jackson-databind")
    implementation("jakarta.annotation:jakarta.annotation-api")
    runtimeOnly("ch.qos.logback:logback-classic")
//    runtimeOnly('org.slf4j:log4j-over-slf4j:2.0.2')
    implementation("io.micronaut:micronaut-validation")
    implementation("io.micronaut.aws:micronaut-function-aws-custom-runtime")
    implementation("io.micronaut.data:micronaut-data-hibernate-jpa")
    implementation("io.micronaut.sql:micronaut-jdbc-hikari")
    runtimeOnly("mysql:mysql-connector-java")
    compileOnly("org.graalvm.nativeimage:svm")

    implementation("io.micronaut.aws:micronaut-function-aws")

    implementation("io.micronaut.aws:micronaut-function-aws-custom-runtime")
    implementation group: 'org.json', name: 'json', version: "${orgJsonVersion}"

    implementation group: 'org.apache.poi', name: 'poi', version: "${poiVersion}"
    implementation group: 'org.apache.poi', name: 'poi-ooxml', version: "${poiVersion}"
    implementation group: 'org.apache.commons', name: 'commons-lang3', version: "${apacheCommons}"
    implementation group: 'com.google.code.gson', name: 'gson', version: "${googleGson}"
//    implementation group: 'org.springframework.boot', name: 'spring-boot-starter-validation', version: "${springValidation}"
    implementation group: 'org.eclipse.persistence', name: 'eclipselink', version: "${eclipseLink}"
//    compileOnly group: 'javax.servlet', name: 'servlet-api', version: "${servletApi}"
    implementation("org.apache.velocity:velocity:${velocity}") {
        exclude group: 'log4j', module: 'log4j'
    }
    implementation("org.apache.velocity:velocity-tools:${velocityTools}") {
        exclude group: 'log4j', module: 'log4j'
    }
    implementation group: 'org.apache.kafka', name: 'kafka-clients', version: "${kafkaClient}"
    implementation group: 'com.google.guava', name: 'guava', version: "${googleGuava}"

}

And below are the arguments which are passed to build native image (mentioned in build.gradle):

tasks.named("dockerfileNative") {
    args(
        "-XX:MaximumHeapSizePercent=80",
        "-Dio.netty.allocator.numDirectArenas=0",
        "-Dio.netty.noPreferDirect=true"
    )
}

graalvmNative.binaries.all {
    buildArgs.add("--no-server -J-Xmx12g -J-Xms4g")
}

And here is the command which I use to build native image for AWS Lambda - ./gradlew clean buildNativeLambda -Pmicronaut.runtime=lambda

Above command generates below Dockerfile:

FROM amazonlinux:latest AS graalvm
ENV LANG=en_US.UTF-8
RUN yum install -y gcc gcc-c++ libc6-dev zlib1g-dev curl bash zlib zlib-devel zlib-static zip tar gzip
RUN curl -4 -L https://github.com/graalvm/graalvm-ce-builds/releases/download/vm-22.1.0/graalvm-ce-java11-linux-amd64-22.1.0.tar.gz -o /tmp/graalvm-ce-java11-linux-amd64-22.1.0.tar.gz
RUN tar -zxf /tmp/graalvm-ce-java11-linux-amd64-22.1.0.tar.gz -C /tmp && mv /tmp/graalvm-ce-java11-22.1.0 /usr/lib/graalvm
RUN rm -rf /tmp/*
RUN /usr/lib/graalvm/bin/gu install native-image
CMD ["/usr/lib/graalvm/bin/native-image"]
ENV PATH=/usr/lib/graalvm/bin:${PATH}
FROM graalvm AS builder
WORKDIR /home/app
COPY layers/libs /home/app/libs
COPY layers/classes /home/app/classes
COPY layers/resources /home/app/resources
COPY layers/application.jar /home/app/application.jar
RUN mkdir /home/app/config-dirs
COPY config-dirs/generateResourcesConfigFile /home/app/config-dirs/generateResourcesConfigFile
RUN native-image -cp /home/app/libs/*.jar:/home/app/resources:/home/app/application.jar --no-fallback -H:Name=application -J--add-exports=org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk=ALL-UNNAMED -J--add-exports=org.graalvm.nativeimage.builder/com.oracle.svm.core.configure=ALL-UNNAMED -H:ConfigurationFileDirectories=/home/app/config-dirs/generateResourcesConfigFile -H:Class=com.example.Application --no-server -J-Xmx12g -J-Xms4g
FROM amazonlinux:latest
WORKDIR /function
RUN yum install -y zip
COPY --from=builder /home/app/application /function/func
RUN echo "#!/bin/sh" >> bootstrap && echo "set -euo pipefail" >> bootstrap && echo "./func -XX:MaximumHeapSizePercent=80 -Dio.netty.allocator.numDirectArenas=0 -Dio.netty.noPreferDirect=true -Djava.library.path=$(pwd)" >> bootstrap
RUN chmod 777 bootstrap
RUN chmod 777 func
RUN zip -j function.zip bootstrap func
ENTRYPOINT ["/function/func"]

And it fails while running RUN native-image step from above Dockerfile with the exception mentioned on this thread.

[jigneshkhatri]

I have posted question on StackOverflow with some more details about the issue I am facing - https://stackoverflow.com/questions/73935636/micronaut-graalvm-issue-in-building-graalvm-native-image-for-micronaut-applica

[jigneshkhatri]

@vjovanov @fniephaus Do we have any fix/solution for this issue? This is a major blocker for me.

[fniephaus]

A fix for this just landed in master (see #5112) but that's unfortunately not going to make it into 22.3. But you should be able to use a 23.0 dev build very soon.