Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Native compiled executable prints log4j2 exception/warning when both Netty and JBoss Logging are on the classpath #33113

Closed
wimdeblauwe opened this issue Nov 12, 2022 · 9 comments
Closed

Native compiled executable prints log4j2 exception/warning when both Netty and JBoss Logging are on the classpath #33113

wimdeblauwe opened this issue Nov 12, 2022 · 9 comments
Labels
for: external-project For an external project and not something we can fix status: superseded An issue that has been superseded by another

Comments

@wimdeblauwe
Copy link
Contributor

wimdeblauwe commented Nov 12, 2022 •
edited

I have a CLI tool using Spring Boot 3.0.0.RC2 with Spring Shell. When I compile it natively and run it, it suddenly now prints this at the start:

ERROR StatusLogger Unable to load services for service class org.apache.logging.log4j.spi.Provider
 java.lang.NoSuchMethodException: no such method: java.util.ServiceLoader.load(Class,ClassLoader)ServiceLoader/invokeStatic
	at java.base@19.0.1/java.lang.invoke.MemberName.makeAccessException(MemberName.java:976)
	at java.base@19.0.1/java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1117)
	at java.base@19.0.1/java.lang.invoke.MethodHandles$Lookup.resolveOrFail(MethodHandles.java:3664)
	at java.base@19.0.1/java.lang.invoke.MethodHandles$Lookup.findStatic(MethodHandles.java:2598)
	at org.apache.logging.log4j.util.ServiceLoaderUtil.loadClassloaderServices(ServiceLoaderUtil.java:91)
	at org.apache.logging.log4j.util.ServiceLoaderUtil.loadServices(ServiceLoaderUtil.java:74)
	at org.apache.logging.log4j.util.ServiceLoaderUtil.loadServices(ServiceLoaderUtil.java:68)
	at org.apache.logging.log4j.util.ProviderUtil.<init>(ProviderUtil.java:67)
	at org.apache.logging.log4j.util.ProviderUtil.lazyInit(ProviderUtil.java:145)
	at org.apache.logging.log4j.util.ProviderUtil.hasProviders(ProviderUtil.java:129)
	at org.apache.logging.log4j.LogManager.<clinit>(LogManager.java:90)
	at org.jboss.logging.LoggerProviders.tryLog4j2(LoggerProviders.java:119)
	at org.jboss.logging.LoggerProviders.findProvider(LoggerProviders.java:84)
	at org.jboss.logging.LoggerProviders.find(LoggerProviders.java:32)
	at org.jboss.logging.LoggerProviders.<clinit>(LoggerProviders.java:29)
	at org.jboss.logging.Logger.getLogger(Logger.java:2465)
	at org.jboss.logging.Logger.doGetMessageLogger(Logger.java:2573)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2530)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2516)
	at org.hibernate.validator.internal.util.logging.LoggerFactory.make(LoggerFactory.java:22)
	at org.hibernate.validator.internal.util.Version.<clinit>(Version.java:20)
	at org.hibernate.validator.internal.engine.AbstractConfigurationImpl.<clinit>(AbstractConfigurationImpl.java:85)
	at java.base@19.0.1/java.lang.Class.ensureInitialized(DynamicHub.java:528)
	at org.hibernate.validator.HibernateValidator.createGenericConfiguration(HibernateValidator.java:33)
	at jakarta.validation.Validation$GenericBootstrapImpl.configure(Validation.java:296)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getMessageInterpolator(MessageInterpolatorFactory.java:79)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getObject(MessageInterpolatorFactory.java:70)
	at org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration.defaultValidator(ValidationAutoConfiguration.java:64)
	at org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration__BeanDefinitions.lambda$getDefaultValidatorInstanceSupplier$0(ValidationAutoConfiguration__BeanDefinitions.java:33)
	at org.springframework.util.function.ThrowingBiFunction.apply(ThrowingBiFunction.java:68)
	at org.springframework.util.function.ThrowingBiFunction.apply(ThrowingBiFunction.java:54)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.lambda$get$2(BeanInstanceSupplier.java:208)
	at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:59)
	at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:47)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.invokeBeanSupplier(BeanInstanceSupplier.java:220)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.get(BeanInstanceSupplier.java:208)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainInstanceFromSupplier(AbstractAutowireCapableBeanFactory.java:1225)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainFromSupplier(AbstractAutowireCapableBeanFactory.java:1210)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1157)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:561)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:961)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:916)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584)
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730)
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:432)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:308)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291)
	at io.github.wimdeblauwe.ttcli.TamingThymeleafCliApplication.main(TamingThymeleafCliApplication.java:10)
Caused by: java.lang.NoSuchMethodError: java.util.ServiceLoader.load(java.lang.Class, java.lang.ClassLoader)
	at org.graalvm.nativeimage.builder/com.oracle.svm.core.methodhandles.Util_java_lang_invoke_MethodHandleNatives.resolve(Target_java_lang_invoke_MethodHandleNatives.java:345)
	at java.base@19.0.1/java.lang.invoke.MethodHandleNatives.resolve(MethodHandleNatives.java:223)
	at java.base@19.0.1/java.lang.invoke.MemberName$Factory.resolve(MemberName.java:1085)
	at java.base@19.0.1/java.lang.invoke.MemberName$Factory.resolveOrFail(MemberName.java:1114)
	... 52 more
ERROR StatusLogger Log4j2 could not find a logging implementation. Please add log4j-core to the classpath. Using SimpleLogger to log to the console...

To be clear: this is not printed when running on the JVM.

I am not using Log4j2, it is not in my dependency tree:

[INFO] --- maven-dependency-plugin:3.3.0:tree (default-cli) @ ttcli ---
[INFO] io.github.wimdeblauwe:ttcli:jar:0.0.3-SNAPSHOT
[INFO] +- org.springframework.boot:spring-boot-starter-web:jar:3.0.0-RC2:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter:jar:3.0.0-RC2:compile
[INFO] |  |  +- org.springframework.boot:spring-boot:jar:3.0.0-RC2:compile
[INFO] |  |  +- org.springframework.boot:spring-boot-autoconfigure:jar:3.0.0-RC2:compile
[INFO] |  |  +- org.springframework.boot:spring-boot-starter-logging:jar:3.0.0-RC2:compile
[INFO] |  |  |  +- ch.qos.logback:logback-classic:jar:1.4.4:compile
[INFO] |  |  |  |  \- ch.qos.logback:logback-core:jar:1.4.4:compile
[INFO] |  |  |  +- org.apache.logging.log4j:log4j-to-slf4j:jar:2.19.0:compile
[INFO] |  |  |  |  \- org.apache.logging.log4j:log4j-api:jar:2.19.0:compile
[INFO] |  |  |  \- org.slf4j:jul-to-slf4j:jar:2.0.3:compile
[INFO] |  |  +- jakarta.annotation:jakarta.annotation-api:jar:2.1.1:compile
[INFO] |  |  \- org.yaml:snakeyaml:jar:1.33:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-json:jar:3.0.0-RC2:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jdk8:jar:2.14.0-rc3:compile
[INFO] |  |  +- com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.14.0-rc3:compile
[INFO] |  |  \- com.fasterxml.jackson.module:jackson-module-parameter-names:jar:2.14.0-rc3:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-tomcat:jar:3.0.0-RC2:compile
[INFO] |  |  +- org.apache.tomcat.embed:tomcat-embed-core:jar:10.1.1:compile
[INFO] |  |  +- org.apache.tomcat.embed:tomcat-embed-el:jar:10.1.1:compile
[INFO] |  |  \- org.apache.tomcat.embed:tomcat-embed-websocket:jar:10.1.1:compile
[INFO] |  +- org.springframework:spring-web:jar:6.0.0-RC4:compile
[INFO] |  |  +- org.springframework:spring-beans:jar:6.0.0-RC4:compile
[INFO] |  |  \- io.micrometer:micrometer-observation:jar:1.10.0:compile
[INFO] |  |     \- io.micrometer:micrometer-commons:jar:1.10.0:compile
[INFO] |  \- org.springframework:spring-webmvc:jar:6.0.0-RC4:compile
[INFO] |     +- org.springframework:spring-aop:jar:6.0.0-RC4:compile
[INFO] |     +- org.springframework:spring-context:jar:6.0.0-RC4:compile
[INFO] |     \- org.springframework:spring-expression:jar:6.0.0-RC4:compile
[INFO] +- org.springframework.boot:spring-boot-starter-webflux:jar:3.0.0-RC2:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-reactor-netty:jar:3.0.0-RC2:compile
[INFO] |  |  \- io.projectreactor.netty:reactor-netty-http:jar:1.1.0:compile
[INFO] |  |     +- io.netty:netty-codec-http:jar:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-common:jar:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-buffer:jar:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-transport:jar:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-codec:jar:4.1.84.Final:compile
[INFO] |  |     |  \- io.netty:netty-handler:jar:4.1.84.Final:compile
[INFO] |  |     +- io.netty:netty-codec-http2:jar:4.1.84.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns:jar:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-resolver:jar:4.1.84.Final:compile
[INFO] |  |     |  \- io.netty:netty-codec-dns:jar:4.1.84.Final:compile
[INFO] |  |     +- io.netty:netty-resolver-dns-native-macos:jar:osx-x86_64:4.1.84.Final:compile
[INFO] |  |     |  \- io.netty:netty-resolver-dns-classes-macos:jar:4.1.84.Final:compile
[INFO] |  |     +- io.netty:netty-transport-native-epoll:jar:linux-x86_64:4.1.84.Final:compile
[INFO] |  |     |  +- io.netty:netty-transport-native-unix-common:jar:4.1.84.Final:compile
[INFO] |  |     |  \- io.netty:netty-transport-classes-epoll:jar:4.1.84.Final:compile
[INFO] |  |     \- io.projectreactor.netty:reactor-netty-core:jar:1.1.0:compile
[INFO] |  |        \- io.netty:netty-handler-proxy:jar:4.1.84.Final:compile
[INFO] |  |           \- io.netty:netty-codec-socks:jar:4.1.84.Final:compile
[INFO] |  \- org.springframework:spring-webflux:jar:6.0.0-RC4:compile
[INFO] |     \- io.projectreactor:reactor-core:jar:3.5.0:compile
[INFO] |        \- org.reactivestreams:reactive-streams:jar:1.0.4:compile
[INFO] +- org.springframework.shell:spring-shell-starter:jar:3.0.0-M2:compile
[INFO] |  +- org.springframework.shell:spring-shell-autoconfigure:jar:3.0.0-M2:compile
[INFO] |  +- org.springframework.shell:spring-shell-core:jar:3.0.0-M2:compile
[INFO] |  |  +- org.springframework.boot:spring-boot-starter-validation:jar:3.0.0-RC2:compile
[INFO] |  |  |  \- org.hibernate.validator:hibernate-validator:jar:8.0.0.Final:compile
[INFO] |  |  |     +- jakarta.validation:jakarta.validation-api:jar:3.0.2:compile
[INFO] |  |  |     +- org.jboss.logging:jboss-logging:jar:3.5.0.Final:compile
[INFO] |  |  |     \- com.fasterxml:classmate:jar:1.5.1:compile
[INFO] |  |  +- org.springframework:spring-messaging:jar:6.0.0-RC4:compile
[INFO] |  |  +- org.jline:jline:jar:3.21.0:compile
[INFO] |  |  +- org.antlr:ST4:jar:4.3.1:compile
[INFO] |  |  |  \- org.antlr:antlr-runtime:jar:3.5.2:compile
[INFO] |  |  \- commons-io:commons-io:jar:2.11.0:compile
[INFO] |  +- org.springframework.shell:spring-shell-standard:jar:3.0.0-M2:compile
[INFO] |  +- org.springframework.shell:spring-shell-standard-commands:jar:3.0.0-M2:compile
[INFO] |  \- org.springframework.shell:spring-shell-table:jar:3.0.0-M2:compile
[INFO] +- org.jsoup:jsoup:jar:1.15.3:compile
[INFO] +- us.codecraft:xsoup:jar:0.3.6:compile
[INFO] |  \- org.assertj:assertj-core:jar:3.23.1:compile
[INFO] |     \- net.bytebuddy:byte-buddy:jar:1.12.18:compile
[INFO] +- com.fasterxml.jackson.core:jackson-databind:jar:2.14.0-rc3:compile
[INFO] |  +- com.fasterxml.jackson.core:jackson-annotations:jar:2.14.0-rc3:compile
[INFO] |  \- com.fasterxml.jackson.core:jackson-core:jar:2.14.0-rc3:compile
[INFO] \- org.springframework.boot:spring-boot-starter-test:jar:3.0.0-RC2:test
[INFO]    +- org.springframework.boot:spring-boot-test:jar:3.0.0-RC2:test
[INFO]    +- org.springframework.boot:spring-boot-test-autoconfigure:jar:3.0.0-RC2:test
[INFO]    +- com.jayway.jsonpath:json-path:jar:2.7.0:test
[INFO]    |  +- net.minidev:json-smart:jar:2.4.8:test
[INFO]    |  |  \- net.minidev:accessors-smart:jar:2.4.8:test
[INFO]    |  |     \- org.ow2.asm:asm:jar:9.1:test
[INFO]    |  \- org.slf4j:slf4j-api:jar:2.0.3:compile
[INFO]    +- jakarta.xml.bind:jakarta.xml.bind-api:jar:4.0.0:test
[INFO]    |  \- jakarta.activation:jakarta.activation-api:jar:2.1.0:test
[INFO]    +- org.hamcrest:hamcrest:jar:2.2:test
[INFO]    +- org.junit.jupiter:junit-jupiter:jar:5.9.1:test
[INFO]    |  +- org.junit.jupiter:junit-jupiter-api:jar:5.9.1:test
[INFO]    |  |  +- org.opentest4j:opentest4j:jar:1.2.0:test
[INFO]    |  |  +- org.junit.platform:junit-platform-commons:jar:1.9.1:test
[INFO]    |  |  \- org.apiguardian:apiguardian-api:jar:1.1.2:test
[INFO]    |  +- org.junit.jupiter:junit-jupiter-params:jar:5.9.1:test
[INFO]    |  \- org.junit.jupiter:junit-jupiter-engine:jar:5.9.1:test
[INFO]    |     \- org.junit.platform:junit-platform-engine:jar:1.9.1:test
[INFO]    +- org.mockito:mockito-core:jar:4.8.1:test
[INFO]    |  +- net.bytebuddy:byte-buddy-agent:jar:1.12.18:test
[INFO]    |  \- org.objenesis:objenesis:jar:3.2:test
[INFO]    +- org.mockito:mockito-junit-jupiter:jar:4.8.1:test
[INFO]    +- org.skyscreamer:jsonassert:jar:1.5.1:test
[INFO]    |  \- com.vaadin.external.google:android-json:jar:0.0.20131108.vaadin1:test
[INFO]    +- org.springframework:spring-core:jar:6.0.0-RC4:compile
[INFO]    |  \- org.springframework:spring-jcl:jar:6.0.0-RC4:compile
[INFO]    +- org.springframework:spring-test:jar:6.0.0-RC4:test
[INFO]    \- org.xmlunit:xmlunit-core:jar:2.9.0:test

I compiled on macOS using GraalVM:

sdk use java 22.3.r19-grl
mvn -Pnative native:compile

Let me know if you need more info. The project can be viewed at https://github.com/wimdeblauwe/ttcli
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Nov 12, 2022
@wimdeblauwe
Copy link
Contributor Author

It seems I can work around the issue by adding this exclusion in my pom.xml:

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.apache.logging.log4j</groupId>
                    <artifactId>log4j-to-slf4j</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

wimdeblauwe added a commit to wimdeblauwe/ttcli that referenced this issue Nov 12, 2022
@wimdeblauwe
fix: Exclude log4j-to-slf4j as a workaround for spring-projects/sprin…
765061b 
…g-boot#33113
@dr-eme
Copy link

dr-eme commented Nov 14, 2022 •
edited

I have a similar issue in Gradle, but the error is shown only when triggering the run from ./gradlew nativeRun, and then stopping the app.

My app uses SLF4J API for logging, and if I simply launch the application from build/nativeCompile/..., no error is shown.

So maybe the issue is with the way the plugins register/trigger the run commands and/or the logger they use.

The proposed workaround (excluding log4j-to-slf4j) seems to solve the issue.

@wilkinsona
Copy link
Member

wilkinsona commented Nov 14, 2022 •
edited

Thanks for reporting this, @wimdeblauwe. It's an unfortunate combination of the way that JBoss Logging behaves and Log4j2, even just its API jar, not playing nicely with GraalVM. We include org.apache.logging.log4j:log4j-to-slf4j in spring-boot-starter-logging so that logging that's using the Log4j2 API can be routed in to SLF4J. If neither your application nor any of its dependencies uses the Log4j2 API for logging, excluding org.apache.logging.log4j:log4j-to-slf4j is a good way to address the problem. Alternatively, setting the org.jboss.logging.provider system property to jdk will fix the problem. Setting it to slf4j should also fix it (and would be a better value) but, for reasons I don't yet understand, it does not help. I'm investigating.

@wilkinsona
Copy link
Member

the error is shown only when triggering the run from ./gradlew nativeRun. If I simply launch the application from build/nativeCompile/..., no error is shown

We've seen somewhat similar behavior. In theory, any application that uses JBoss logging should be affected. However, that is not the case. It appears that something (initialization order?) causes JBoss Logging to behave differently so the problem doesn't always occur.

@wilkinsona
Copy link
Member

Setting it to slf4j should also fix it (and would be a better value) but, for reasons I don't yet understand, it does not help. I'm investigating.

When configured to try using SLF4J, JBoss Logging relies upon reflection to analyse the methods of org.slf4j.spi.LocationAwareLogger. This fails in a native image:

java.lang.NoSuchMethodError: Cannot find LocationAwareLogger.log() method
	at org.jboss.logging.Slf4jLocationAwareLogger.<clinit>(Slf4jLocationAwareLogger.java:47)
	at org.jboss.logging.Slf4jLoggerProvider.getLogger(Slf4jLoggerProvider.java:38)
	at org.jboss.logging.LoggerProviders.logProvider(LoggerProviders.java:151)
	at org.jboss.logging.LoggerProviders.trySlf4j(LoggerProviders.java:113)
	at org.jboss.logging.LoggerProviders.findProvider(LoggerProviders.java:53)
	at org.jboss.logging.LoggerProviders.find(LoggerProviders.java:32)
	at org.jboss.logging.LoggerProviders.<clinit>(LoggerProviders.java:29)
	at org.jboss.logging.Logger.getLogger(Logger.java:2465)
	at org.jboss.logging.Logger.doGetMessageLogger(Logger.java:2573)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2530)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2516)
	at org.hibernate.validator.internal.util.logging.LoggerFactory.make(LoggerFactory.java:22)
	at org.hibernate.validator.internal.util.Version.<clinit>(Version.java:20)
	at org.hibernate.validator.internal.engine.AbstractConfigurationImpl.<clinit>(AbstractConfigurationImpl.java:85)
	at java.base@17.0.5/java.lang.Class.ensureInitialized(DynamicHub.java:528)
	at org.hibernate.validator.HibernateValidator.createGenericConfiguration(HibernateValidator.java:33)
	at jakarta.validation.Validation$GenericBootstrapImpl.configure(Validation.java:296)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getMessageInterpolator(MessageInterpolatorFactory.java:79)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getObject(MessageInterpolatorFactory.java:70)
	at org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration.defaultValidator(ValidationAutoConfiguration.java:64)
	at org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration__BeanDefinitions.lambda$getDefaultValidatorInstanceSupplier$0(ValidationAutoConfiguration__BeanDefinitions.java:33)
	at org.springframework.util.function.ThrowingBiFunction.apply(ThrowingBiFunction.java:68)
	at org.springframework.util.function.ThrowingBiFunction.apply(ThrowingBiFunction.java:54)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.lambda$get$2(BeanInstanceSupplier.java:208)
	at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:59)
	at org.springframework.util.function.ThrowingSupplier.get(ThrowingSupplier.java:47)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.invokeBeanSupplier(BeanInstanceSupplier.java:220)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.get(BeanInstanceSupplier.java:208)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainInstanceFromSupplier(AbstractAutowireCapableBeanFactory.java:1225)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainFromSupplier(AbstractAutowireCapableBeanFactory.java:1210)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1157)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:561)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:961)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:916)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584)
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730)
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:432)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:308)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291)
	at io.github.wimdeblauwe.ttcli.TamingThymeleafCliApplication.main(TamingThymeleafCliApplication.java:10)

@wilkinsona
Copy link
Member

When log4j-to-slf4j is on the classpath, JBoss Logging uses org.jboss.logging.Log4j2LoggerProvider on the JVM. This means that the log routing is JBoss Logging -> Log4j2 API -> SLF4J -> Logback. In a native image, Log4j2 fails and org.jboss.logging.JDKLoggerProvider is used instead. This means that the log routing is JBoss Logging -> JDK -> SLF4J -> Logback. We should avoid this difference in routing if we can. It's also less efficient than it could be, both on the JVM and in a native image. It would be preferable to omit the second step and use JBoss Logging -> SLF4J -> Logback instead. For this to work in a native image, reachability metadata for JBoss Logging introspecting org.slf4j.spi.LocationAwareLogger is required.

@wilkinsona
Copy link
Member

In our Hibernate Validator smoke test, we don't see the unwanted error-level logging. This is because the attempt to use Log4j2 fails differently:

java.lang.ExceptionInInitializerError
	at org.apache.logging.log4j.LogManager.<clinit>(LogManager.java:61)
	at org.jboss.logging.LoggerProviders.tryLog4j2(LoggerProviders.java:126)
	at org.jboss.logging.LoggerProviders.findProvider(LoggerProviders.java:88)
	at org.jboss.logging.LoggerProviders.find(LoggerProviders.java:32)
	at org.jboss.logging.LoggerProviders.<clinit>(LoggerProviders.java:29)
	at org.jboss.logging.Logger.getLogger(Logger.java:2465)
	at org.jboss.logging.Logger.doGetMessageLogger(Logger.java:2573)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2530)
	at org.jboss.logging.Logger.getMessageLogger(Logger.java:2516)
	at org.hibernate.validator.internal.util.logging.LoggerFactory.make(LoggerFactory.java:22)
	at org.hibernate.validator.internal.util.Version.<clinit>(Version.java:20)
	at org.hibernate.validator.internal.engine.AbstractConfigurationImpl.<clinit>(AbstractConfigurationImpl.java:85)
	at java.base@17.0.5/java.lang.Class.ensureInitialized(DynamicHub.java:528)
	at org.hibernate.validator.HibernateValidator.createGenericConfiguration(HibernateValidator.java:33)
	at jakarta.validation.Validation$GenericBootstrapImpl.configure(Validation.java:296)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getMessageInterpolator(MessageInterpolatorFactory.java:79)
	at org.springframework.boot.validation.MessageInterpolatorFactory.getObject(MessageInterpolatorFactory.java:70)
	at org.springframework.boot.context.properties.ConfigurationPropertiesJsr303Validator$Delegate.<init>(ConfigurationPropertiesJsr303Validator.java:68)
	at org.springframework.boot.context.properties.ConfigurationPropertiesJsr303Validator.<init>(ConfigurationPropertiesJsr303Validator.java:41)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBinder.getJsr303Validator(ConfigurationPropertiesBinder.java:154)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBinder.getValidators(ConfigurationPropertiesBinder.java:144)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBinder.getBindHandler(ConfigurationPropertiesBinder.java:112)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBinder.bind(ConfigurationPropertiesBinder.java:93)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor.bind(ConfigurationPropertiesBindingPostProcessor.java:89)
	at org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor.postProcessBeforeInitialization(ConfigurationPropertiesBindingPostProcessor.java:78)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:420)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1745)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:599)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
	at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:254)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1405)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1325)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.resolveArgument(BeanInstanceSupplier.java:334)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.resolveArguments(BeanInstanceSupplier.java:271)
	at org.springframework.beans.factory.aot.BeanInstanceSupplier.get(BeanInstanceSupplier.java:206)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainInstanceFromSupplier(AbstractAutowireCapableBeanFactory.java:1225)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.obtainFromSupplier(AbstractAutowireCapableBeanFactory.java:1210)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1157)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:561)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:521)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:326)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:324)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:961)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:916)
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:584)
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146)
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:730)
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:432)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:308)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1302)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1291)
	at com.example.validation.ValidationApplication.main(ValidationApplication.java:10)
Caused by: java.lang.IllegalStateException: java.lang.InstantiationException: org.apache.logging.log4j.message.DefaultFlowMessageFactory
	at org.apache.logging.log4j.spi.AbstractLogger.createDefaultFlowMessageFactory(AbstractLogger.java:246)
	at org.apache.logging.log4j.spi.AbstractLogger.<init>(AbstractLogger.java:144)
	at org.apache.logging.log4j.status.StatusLogger.<init>(StatusLogger.java:133)
	at org.apache.logging.log4j.status.StatusLogger.<clinit>(StatusLogger.java:85)
	... 58 more
Caused by: java.lang.InstantiationException: org.apache.logging.log4j.message.DefaultFlowMessageFactory
	at java.base@17.0.5/java.lang.Class.newInstance(DynamicHub.java:639)
	at org.apache.logging.log4j.spi.AbstractLogger.createDefaultFlowMessageFactory(AbstractLogger.java:244)
	... 61 more
Caused by: java.lang.NoSuchMethodException: org.apache.logging.log4j.message.DefaultFlowMessageFactory.<init>()
	at java.base@17.0.5/java.lang.Class.getConstructor0(DynamicHub.java:3585)
	at java.base@17.0.5/java.lang.Class.newInstance(DynamicHub.java:626)
	... 62 more

It's failed earlier and, crucially, before the point at which the Log4j2 API jar performs the unwanted logging. I don't yet understand why, apparently, it would sometimes be possible to call org.apache.logging.log4j.message.DefaultFlowMessageFactory.class.newInstance() in a native image and sometimes it would not.

@wilkinsona
Copy link
Member

org.apache.logging.log4j.message.DefaultFlowMessageFactory is accessible reflectively when Netty's on the classpath. This is due to its reachability metadata. Given that Log4j2 doesn't work in a native image and that Netty prefers SLF4J over Log4j2, I wonder if this metadata is doing more harm than good.

@wilkinsona wilkinsona changed the title Native compiled executable prints log4j2 exception/warning Native compiled executable prints log4j2 exception/warning when both Netty and JBoss Logging are on the classpath Nov 14, 2022
@wilkinsona
Copy link
Member

wilkinsona commented Nov 14, 2022 •
edited

I've opened oracle/graalvm-reachability-metadata#108 to fix the reachability metadata for Netty. With this change in place, Log4j2 no longer performs the error-level logging of the exception. Until this change is available, please continue to exclude the org.apache.logging.log4j:log4j-to-slf4j dependency or set the org.jboss.logging.provider system property to jdk.

I've also opened #33155 to address the different providers on the JVM and in a native image that was discovered while investigating this issue.

@wilkinsona wilkinsona closed this as not planned Won't fix, can't repro, duplicate, stale Nov 14, 2022
@wilkinsona wilkinsona added for: external-project For an external project and not something we can fix status: superseded An issue that has been superseded by another and removed status: waiting-for-triage An issue we've not yet triaged labels Nov 14, 2022
@wilkinsona wilkinsona mentioned this issue Nov 15, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
for: external-project For an external project and not something we can fix status: superseded An issue that has been superseded by another
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@wilkinsona @wimdeblauwe @spring-projects-issues @dr-eme