Using spring boot 3.2.2.
project available at https://github.com/Jojoooo1/spring-boot-api/tree/feature/add-graalvm
Configuration
pom.xml:
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
<configuration>
<image>
<env>
<BP_NATIVE_IMAGE_BUILD_ARGUMENTS>
-H:+AddAllCharsets
-H:+ReportExceptionStackTraces
--initialize-at-run-time=io.netty.handler.ssl.BouncyCastleAlpnSslUtils
--initialize-at-build-time=ch.qos.logback,org.slf4j.LoggerFactory
</BP_NATIVE_IMAGE_BUILD_ARGUMENTS>
<BP_JVM_VERSION>21</BP_JVM_VERSION>
</env>
<createdDate>${maven.build.timestamp}</createdDate>
</image>
</configuration>
</plugin>
logback-spring.xml:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
<springProfile name="!json-logs">
<root level="INFO">
<appender-ref ref="CONSOLE"/>
</root>
</springProfile>
<springProfile name="json-logs">
<appender name="json" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
<providers>
<timestamp>
<timeZone>America/Sao_Paulo</timeZone>
</timestamp>
<pattern>
<pattern>
{
"level": "%level",
"company": "%mdc{company}",
"user": "%mdc{user}",
"message": "%message",
"traceId": "%mdc{traceId}",
"spanId": "%mdc{spanId}",
"logger": "%logger",
"thread": "%thread"
}
</pattern>
</pattern>
<stackTrace>
<fieldName>stackTrace</fieldName>
<throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
<maxDepthPerThrowable>4</maxDepthPerThrowable>
<shortenedClassNameLength>30</shortenedClassNameLength>
<rootCauseFirst>true</rootCauseFirst>
</throwableConverter>
</stackTrace>
</providers>
</encoder>
</appender>
<root level="INFO">
<appender-ref ref="json"/>
</root>
</springProfile>
</configuration>
building image with: SPRING_PROFILES_ACTIVE=dev mvn clean -Pnative -DskipTests spring-boot:build-image
run the image: docker run <image-id>
The container fails with:
Logging system failed to initialize using configuration from 'null'
java.lang.IllegalStateException: Logback configuration error detected:
ERROR in ch.qos.logback.core.pattern.parser.Compiler@3fdbc37f - Failed to instantiate converter class [ch.qos.logback.classic.pattern.DateConverter] for keyword [d] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.DateConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@3fdbc37f - [d] is not a valid conversion word
ERROR in ch.qos.logback.core.pattern.parser.Compiler@750b517c - Failed to instantiate converter class [ch.qos.logback.classic.pattern.LevelConverter] for keyword [p] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.LevelConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@750b517c - [p] is not a valid conversion word
ERROR in ch.qos.logback.core.pattern.parser.Compiler@1870bca7 - Failed to instantiate converter class [ch.qos.logback.classic.pattern.ThreadConverter] for keyword [t] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.ThreadConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@1870bca7 - [t] is not a valid conversion word
ERROR in ch.qos.logback.core.pattern.parser.Compiler@335702a4 - Failed to instantiate converter class [ch.qos.logback.classic.pattern.LoggerConverter] for keyword [logger] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.LoggerConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@335702a4 - [logger] is not a valid conversion word
ERROR in ch.qos.logback.core.pattern.parser.Compiler@72538a5c - Failed to instantiate converter class [ch.qos.logback.classic.pattern.MessageConverter] for keyword [m] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.MessageConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@72538a5c - [m] is not a valid conversion word
ERROR in ch.qos.logback.core.pattern.parser.Compiler@72538a5c - Failed to instantiate converter class [ch.qos.logback.classic.pattern.LineSeparatorConverter] for keyword [n] ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate type ch.qos.logback.classic.pattern.LineSeparatorConverter
ERROR in ch.qos.logback.core.pattern.parser.Compiler@72538a5c - [n] is not a valid conversion word
Comment From: Jojoooo1
The documentation makes it pretty confusing:
Logback is supported, including XML configuration. XML configuration is loaded at build time during AOT processing and translated into a fixed, native-friendly format. As a result, loading different XML configuration at runtime is not supported.
Fixed it by adding:
- -H:ReflectionConfigurationFiles=/workspace/META-INF/native-image/logback-config.json
- src/main/resources/META-INF/native-image/logback-config.json
[
{
"name": "ch.qos.logback.classic.AsyncAppender",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.encoder.PatternLayoutEncoder",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.DateConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.LevelConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.LineSeparatorConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.LoggerConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.MessageConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.classic.pattern.ThreadConverter",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.core.ConsoleAppender",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
},
{
"name": "ch.qos.logback.core.FileAppender",
"allDeclaredConstructors": true,
"allPublicConstructors": true,
"allDeclaredMethods": true,
"allPublicMethods": true,
"allDeclaredFields": true,
"allPublicFields": true,
"allDeclaredClasses": true,
"allPublicClasses": true
}
]
Comment From: wilkinsona
I tried to reproduce this locally using SPRING_PROFILES_ACTIVE=dev ./mvnw -Pnative native:compile with Liberica-NIK-23.1.0-1 but compilation of the native image failed with the following:
Image heap writing found a class not seen during static analysis. Did a static field or an object referenced from a static field change during native image generation? For example, a lazily initialized cache could have been initialized during image generation, in which case you need to force eager initialization of the cache before static analysis or reset the cache using a field value recomputation.
class: io.opentelemetry.sdk.common.export.RetryPolicy
reachable through:
object: [Ljava.lang.Class;@3b4dbac0 of class: java.lang.Class[]
object: com.oracle.svm.core.code.ImageCodeInfo@3ff3fc3c of class: com.oracle.svm.core.code.ImageCodeInfo
root: com.oracle.svm.core.code.ImageCodeInfo.prepareCodeInfo()
at org.graalvm.nativeimage.builder/com.oracle.svm.core.util.UserError.abort(UserError.java:73)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.image.NativeImageHeap.reportIllegalType(NativeImageHeap.java:592)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.image.NativeImageHeap.addConstant(NativeImageHeap.java:303)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.image.NativeImageHeap.processAddObjectWorklist(NativeImageHeap.java:705)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.image.NativeImageHeap.addTrailingObjects(NativeImageHeap.java:202)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.buildNativeImageHeap(NativeImageGenerator.java:761)
at org.graalvm.nativeimage.builder/com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:698)
... 5 more
This may be a GraalVM bug but it's unrelated to your Logback problem. To allow us to move past it and focus on Logback for now, please provide a minimal sample (one with as few dependencies and as little configuration as possible) that reproduces the problem.
Comment From: Jojoooo1
Hi @wilkinsona, you can find a minimal sample project to reproduce the error at https://github.com/Jojoooo1/spring-minimal-sample-39650/tree/main . It seems to be coming from the spring-boot-starter-webflux
Comment From: wilkinsona
Thanks.
You aren't using the native profile in the recommended way. You need to declare the native-maven-plugin as well:
<plugin>
<groupId>org.graalvm.buildtools</groupId>
<artifactId>native-maven-plugin</artifactId>
</plugin>
Including this plugin enables the inclusion of reachability metadata in the jar file which buildpacks then use when creating the native image. Without the reachability metadata, Logback does not work correctly. I can see that you tried to work around this by initialising Logback at build time. That configuration should be removed and the native-maven-plugin dependency should be added instead.
With these changes in place, your application builds and starts successfully:
$ docker run docker.io/library/demo:0.0.1-SNAPSHOT
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v3.2.2)
2024-02-23T14:00:49.120Z INFO 1 --- [ main] com.example.demo.DemoApplication : Starting AOT-processed DemoApplication using Java 21.0.2 with PID 1 (/workspace/com.example.demo.DemoApplication started by cnb in /workspace)
2024-02-23T14:00:49.120Z INFO 1 --- [ main] com.example.demo.DemoApplication : No active profile set, falling back to 1 default profile: "default"
2024-02-23T14:00:49.133Z INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port 8080 (http)
2024-02-23T14:00:49.134Z INFO 1 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2024-02-23T14:00:49.134Z INFO 1 --- [ main] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.18]
2024-02-23T14:00:49.143Z INFO 1 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2024-02-23T14:00:49.143Z INFO 1 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 23 ms
2024-02-23T14:00:49.174Z INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port 8080 (http) with context path ''
2024-02-23T14:00:49.175Z INFO 1 --- [ main] com.example.demo.DemoApplication : Started DemoApplication in 0.07 seconds (process running for 0.076)
Comment From: Jojoooo1
@wilkinsona from what I understand it is already included in the native profile https://github.com/spring-projects/spring-boot/blob/0bc5e2743b22427a5c78c0b626400017c49b6897/spring-boot-project/spring-boot-starters/spring-boot-starter-parent/build.gradle#L232 this is why I did not use it.
Comment From: wilkinsona
There's plugin management in the parent's native profile but no plugin dependency declaration. Plugin management only has an effect when a dependency on the managed plugin is declared.
Comment From: Jojoooo1
Thank you very much @wilkinsona I did not know about that!