Login/Register
Log4j2 - Unrecognized conversion specifier [xwEx] starting at position 160 in conversion pattern
Asked Answered
spring-bootlogginglog4j2
H

5

9

I have a SpringBoot application in a maven multimodule project, and I am using Log4j2 for logging.

When I run the build with tests, some of the modules has a weird logging exception, and logs more lines from unknown (not mine) classes.

This is the exception:

2018-06-04 14:16:26,791 main ERROR Error creating converter for xwEx java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.logging.log4j.core.pattern.PatternParser.createConverter(PatternParser.java:583)
    at org.apache.logging.log4j.core.pattern.PatternParser.finalizeConverter(PatternParser.java:639)
    at org.apache.logging.log4j.core.pattern.PatternParser.parse(PatternParser.java:415)
    at org.apache.logging.log4j.core.pattern.PatternParser.parse(PatternParser.java:177)
    at org.apache.logging.log4j.core.layout.PatternLayout$SerializerBuilder.build(PatternLayout.java:377)
    at org.apache.logging.log4j.core.layout.PatternLayout.<init>(PatternLayout.java:129)
    at org.apache.logging.log4j.core.layout.PatternLayout.<init>(PatternLayout.java:59)
    at org.apache.logging.log4j.core.layout.PatternLayout$Builder.build(PatternLayout.java:660)
    at org.apache.logging.log4j.core.layout.PatternLayout$Builder.build(PatternLayout.java:517)
    at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:122)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:958)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:898)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:890)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:890)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:513)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:237)
    at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:249)
    at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:545)
    at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:261)
    at org.springframework.boot.logging.log4j2.Log4J2LoggingSystem.loadConfiguration(Log4J2LoggingSystem.java:176)
    at org.springframework.boot.logging.log4j2.Log4J2LoggingSystem.loadDefaults(Log4J2LoggingSystem.java:159)
    at org.springframework.boot.logging.AbstractLoggingSystem.initializeWithConventions(AbstractLoggingSystem.java:84)
    at org.springframework.boot.logging.AbstractLoggingSystem.initialize(AbstractLoggingSystem.java:59)
    at org.springframework.boot.logging.log4j2.Log4J2LoggingSystem.initialize(Log4J2LoggingSystem.java:148)
    at org.springframework.boot.logging.LoggingApplicationListener.initializeSystem(LoggingApplicationListener.java:303)
    at org.springframework.boot.logging.LoggingApplicationListener.initialize(LoggingApplicationListener.java:276)
    at org.springframework.boot.logging.LoggingApplicationListener.onApplicationEnvironmentPreparedEvent(LoggingApplicationListener.java:239)
    at org.springframework.boot.logging.LoggingApplicationListener.onApplicationEvent(LoggingApplicationListener.java:212)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:167)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:122)
    at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:73)
    at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:54)
    at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:336)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)
    at org.springframework.boot.test.context.SpringBootContextLoader.loadContext(SpringBootContextLoader.java:120)
    at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContextInternal(DefaultCacheAwareContextLoaderDelegate.java:98)
    at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:116)
    at org.springframework.test.context.support.DefaultTestContext.getApplicationContext(DefaultTestContext.java:83)
    at org.springframework.test.context.web.ServletTestExecutionListener.setUpRequestContextIfNecessary(ServletTestExecutionListener.java:189)
    at org.springframework.test.context.web.ServletTestExecutionListener.prepareTestInstance(ServletTestExecutionListener.java:131)
    at org.springframework.test.context.TestContextManager.prepareTestInstance(TestContextManager.java:230)
    at org.spockframework.spring.SpringTestContextManager.prepareTestInstance(SpringTestContextManager.java:50)
    at org.spockframework.spring.SpringInterceptor.interceptSetupMethod(SpringInterceptor.java:42)
    at org.spockframework.runtime.extension.AbstractMethodInterceptor.intercept(AbstractMethodInterceptor.java:28)
    at org.spockframework.runtime.extension.MethodInvocation.proceed(MethodInvocation.java:87)
    at org.spockframework.runtime.BaseSpecRunner.invoke(BaseSpecRunner.java:472)
    at org.spockframework.runtime.BaseSpecRunner.runSetup(BaseSpecRunner.java:375)
    at org.spockframework.runtime.BaseSpecRunner.runSetup(BaseSpecRunner.java:370)
    at org.spockframework.runtime.BaseSpecRunner.doRunIteration(BaseSpecRunner.java:323)
    at org.spockframework.runtime.BaseSpecRunner$6.invoke(BaseSpecRunner.java:309)
    at org.spockframework.runtime.BaseSpecRunner.invokeRaw(BaseSpecRunner.java:481)
    at org.spockframework.runtime.BaseSpecRunner.invoke(BaseSpecRunner.java:464)
    at org.spockframework.runtime.BaseSpecRunner.runIteration(BaseSpecRunner.java:288)
    at org.spockframework.runtime.BaseSpecRunner.initializeAndRunIteration(BaseSpecRunner.java:278)
    at org.spockframework.runtime.BaseSpecRunner.runSimpleFeature(BaseSpecRunner.java:269)
    at org.spockframework.runtime.BaseSpecRunner.doRunFeature(BaseSpecRunner.java:263)
    at org.spockframework.runtime.BaseSpecRunner$5.invoke(BaseSpecRunner.java:246)
    at org.spockframework.runtime.BaseSpecRunner.invokeRaw(BaseSpecRunner.java:481)
    at org.spockframework.runtime.BaseSpecRunner.invoke(BaseSpecRunner.java:464)
    at org.spockframework.runtime.BaseSpecRunner.runFeature(BaseSpecRunner.java:238)
    at org.spockframework.runtime.BaseSpecRunner.runFeatures(BaseSpecRunner.java:188)
    at org.spockframework.runtime.BaseSpecRunner.doRunSpec(BaseSpecRunner.java:98)
    at org.spockframework.runtime.BaseSpecRunner$1.invoke(BaseSpecRunner.java:84)
    at org.spockframework.runtime.BaseSpecRunner.invokeRaw(BaseSpecRunner.java:481)
    at org.spockframework.runtime.BaseSpecRunner.invoke(BaseSpecRunner.java:464)
    at org.spockframework.runtime.BaseSpecRunner.runSpec(BaseSpecRunner.java:76)
    at org.spockframework.runtime.BaseSpecRunner.run(BaseSpecRunner.java:67)
    at org.spockframework.runtime.Sputnik.run(Sputnik.java:63)
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:283)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:173)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:153)
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:128)
    at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
Caused by: java.lang.NoSuchMethodError: org.apache.logging.log4j.core.pattern.ThrowablePatternConverter.<init>(Ljava/lang/String;Ljava/lang/String;[Ljava/lang/String;)V
    at org.springframework.boot.logging.log4j2.ExtendedWhitespaceThrowablePatternConverter.<init>(ExtendedWhitespaceThrowablePatternConverter.java:42)
    at org.springframework.boot.logging.log4j2.ExtendedWhitespaceThrowablePatternConverter.newInstance(ExtendedWhitespaceThrowablePatternConverter.java:63)
    ... 80 more

Then I get this line:

2018-06-04 14:16:26,805 main ERROR Unrecognized conversion specifier [xwEx] starting at position 160 in conversion pattern.

And then I see unknown logs (the first two rows about my class):

2018-06-04 14:16:27.118  INFO 1244 --- [           main] c.m.a.MyTest   : Starting MyTest on blablabla
%xwEx2018-06-04 14:16:27.148  INFO 1244 --- [           main] c.m.a.MyTest   : No active profile set, falling back to default profiles: default
%xwEx2018-06-04 14:16:27.298  INFO 1244 --- [           main] o.s.w.c.s.GenericWebApplicationContext   : Refreshing org.springframework.web.context.support.GenericWebApplicationContext@51a07eac: startup date [Mon Jun 04 14:16:27 CEST 2018]; root of context hierarchy
%xwEx2018-06-04 14:16:31.216  INFO 1244 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration' of type [class org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
%xwEx2018-06-04 14:16:32.022  INFO 1244 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'validator' of type [class org.springframework.validation.beanvalidation.LocalValidatorFactoryBean] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
%xwEx2018-06-04 14:16:32.423  INFO 1244 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [class org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$a851eb8b] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
%xwEx2018-06-04 14:16:36.988  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdateWithoutAffectedRowsCheck(java.lang.String,java.lang.String,java.util.List)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.
%xwEx2018-06-04 14:16:36.997  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdateWithAffectedRowsCheck(java.lang.String,java.lang.String,java.util.List)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.
%xwEx2018-06-04 14:16:36.998  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdate(java.lang.String,java.lang.String,java.util.List,boolean)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.
%xwEx2018-06-04 14:16:37.567  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdateWithoutAffectedRowsCheck(java.lang.String,java.lang.String,java.util.List)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.
%xwEx2018-06-04 14:16:37.568  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdateWithAffectedRowsCheck(java.lang.String,java.lang.String,java.util.List)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.
%xwEx2018-06-04 14:16:37.569  INFO 1244 --- [           main] o.s.a.f.CglibAopProxy                    : Unable to proxy method [protected final int com.globalblue.refunding.repository.scheduler.SchedulerBaseRepository.doInClauseUpdate(java.lang.String,java.lang.String,java.util.List,boolean)] because it is final: All calls to this method via a proxy will NOT be routed to the target instance.

This is my log4j2-test.xml in the module where I get these weird things:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="stdout">
            <PatternLayout pattern="MyApp: %d{yyyy-MM-dd HH:mm:ss,SSS} %5p [%t] %c{1.}:%L - %m%n"/>
        </Console>
    </Appenders>

    <Loggers>
        <Logger name="com.my.app" level="debug" additivity="false">
            <appender-ref ref="stdout"/>
        </Logger>
        <Logger name="org.springframework" level="warn" additivity="false">
            <Appender-ref ref="stdout"/>
        </Logger>
        <Logger name="org.springframework.context.annotation.ConfigurationClassEnhancer" level="error"
                additivity="false">
            <Appender-ref ref="stdout"/>
        </Logger>
        <Root level="info">
            <Appender-ref ref="stdout"/>
        </Root>
    </Loggers>
</Configuration>

And finally the pom.xml for the module:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-test</artifactId>
    <scope>test</scope>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-configuration-processor</artifactId>
    <optional>true</optional>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-jdbc</artifactId>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-tx</artifactId>
</dependency>

<!-- Log4j Start -->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-web</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-slf4j-impl</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-jul</artifactId>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-jcl</artifactId>
</dependency>
<dependency>
    <groupId>org.dblock.log4jna</groupId>
    <artifactId>log4jna-api</artifactId>
</dependency>
Hippodrome answered 4/6, 2018 at 12:28 Comment(5)
Is it possible that you have code somewhere that is programmatically changing the configuration? – Pimp
no, this is all I have – Hippodrome
@Hippodrome so, did you manage to fix this error? I ran in to the same one. – Diminished
Me to... still there this issue? – Acrostic
no, the exception is still there – Hippodrome
K
4

There is an issue reported that says Spring Boot 1.5 is not compatible with Log4j 2.8. https://github.com/spring-projects/spring-boot/issues/9172

I was getting errors like yours with Spring Boot 1.5 and Log4j 2.8.2, and the errors away when I switched to Log4j 2.7

Kalie answered 6/3, 2019 at 22:10 Comment(2)
I was facing the same issue and this worked for me! – Fadein
Unfortunately the downgrade is no more a good solution due to the famous "log4shell" vulnerability. – Pterosaur
B
3

springboot1 default log4j.xml use pattern: %xwEx is not supported by 2.8+, but we can override the pattern by set environment variable LOG_EXCEPTION_CONVERSION_WORD like: %throwable

@SpringBootApplication
public class Application {
    public static void main(String[] args) {
        System.setProperty("LOG_EXCEPTION_CONVERSION_WORD", "%throwable");
        SpringApplication.run(Application.class, args);
    }
}
Bellerophon answered 16/12, 2021 at 3:6 Comment(1)
This didn't work for me, and I don't have custom log4j2 configuration. So I copied log4j2.xml from github.com/spring-projects/spring-boot/blob/1.5.x/spring-boot/… to "resources" directory and updated the "LOG_EXCEPTION_CONVERSION_WORD" to "%throwable" which fixed the issue. – Floury
P
3

I think that existing answers are correct but incomplete.

You get that error if both the following conditions occur:

  1. You are using an old version of spring-boot with a recent version of Log4J2 (not ideal but possible; you are upgrading Log4J2 due to "Log4shell" vulnerability, right?)
  2. You are using the default logging config file provided by spring-boot (it is /org/springframework/boot/logging/log4j2/log4j2.xml in spring-boot-x.x.x.RELEASE.jar). This is the real problem.

The default config file exists to allow a quick setup of new applications. Unfortunately it is not compatible with Log4J 2.8+.

Probably you want to use your own configuration and, perhaps, you have already prepared your config file but the application hasn't found it.

Possible solutions:

  1. Upgrade spring-boot or downgrade Log4J2 (downgrading is not recommended, of course).

  2. If you really want to use the default cfg (really?), set this environment variable: LOG_EXCEPTION_CONVERSION_WORD=%throwable as suggested by tsingke

  3. Ensure that your own log4j2.xml or, even better, log4j2-spring.xml is in the classpath or in a path pointed out by the logging.config environment variable (see Custom Log Configuration).

I have used solution #3.

Side note: if you upgrade Log4J but continue using spring-boot 1.x you suffer from other vulnerabilities, so it should be just the first step, even if your boss (or your customer) only cares about Log4shell!

Pterosaur answered 28/1, 2022 at 17:29 Comment(0)
C
1

I faced this problem while upgrading to log4j 2.17.1 (due to those vulnerabilities). On my project I need to keep SpringBoot 1.5.

I solved it just by placing the log4j2.xml file into the "resources" folder and not at the root folder as it was before. Yes, it doesn't make sense. It doesn't need to be a complex xml, as mine is very simple, and doesn't need to have any property related to 'xwEx'.

Although on Internet people say log4j 2.8+ and Spring 1.5 are incompatible, it doesn't seem to be the cause of this specific problem.

I discovered it after trying a lot of possibilities, fighting with dependencies and finally getting hopeless and trying everything haha.

Cart answered 17/1, 2022 at 21:14 Comment(0)
A
0

Try modifying your log4j2-test.xml file to match the following:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration name="${sys:LOG_FILE}" status="WARN"
    strict="true">
    <Properties>
        <Property name="ROLLING_LOG_FILE_NAME"
            value="${sys:LOG_FILE}" />
        <Property name="APP_LOG_FOLDER"
            value="${ROLLING_LOG_FILE_NAME}" />
        <Property name="APP_LOG_BASE_DIRECTORY"
            value="${sys:dtep.logs.home}${sys:file.separator}${APP_LOG_FOLDER}" />
        <Property name="CONSOLE_LOG_PATTERN"
            value="%date{yyyy-MM-dd HH:mm:ss.SSS} %highlight{%5level} %style{%5processId}{normal, blue} --- [%15thread] %style{%logger{1.}}{normal, cyan} : %message%n%throwable%n" />
        <Property name="FILE_LOG_PATTERN"
            value="%date{yyyy-MM-dd HH:mm:ss.SSS} %5level %5processId --- [%15thread] %logger{1.} : %message%n%throwable%n" />
    </Properties>
    <Appenders>
        <Appender type="Console" name="Console" target="SYSTEM_OUT">
            <Layout type="PatternLayout" pattern="${CONSOLE_LOG_PATTERN}" />
        </Appender>
        <Appender type="RollingFile" name="RollingFile"
            fileName="${APP_LOG_BASE_DIRECTORY}${sys:file.separator}${ROLLING_LOG_FILE_NAME}.log"
            filePattern="${APP_LOG_BASE_DIRECTORY}${sys:file.separator}$${date:yyyy}${sys:file.separator}$${date:MMM}${sys:file.separator}${ROLLING_LOG_FILE_NAME}_%d{yyyy-MM-dd}_%i.log">
            <Layout type="PatternLayout" pattern="${FILE_LOG_PATTERN}" />
            <Policies>
                <Policy type="TimeBasedTriggeringPolicy" />
                <Policy type="SizeBasedTriggeringPolicy" size="1KB" />
            </Policies>
            <Strategy type="DefaultRolloverStrategy" fileIndex="nomax">
                <Delete basePath="${APP_LOG_BASE_DIRECTORY}" maxDepth="5"
                    testMode="false">
                    <IfFileName
                        glob="**${sys:file.separator}${ROLLING_LOG_FILE_NAME}_*.log">
                        <IfLastModified age="1m">
                            <IfAny>
                                <IfAccumulatedFileSize exceeds="3 KB" />
                                <IfAccumulatedFileCount exceeds="3" />
                            </IfAny>
                        </IfLastModified>
                    </IfFileName>
                </Delete>
            </Strategy>
        </Appender>
    </Appenders>
    <Loggers>
        <Root level="TRACE">
            <AppenderRef ref="Console">
                <Filters>
                    <Filter type="ThresholdFilter" level="INFO" onMatch="ACCEPT"
                        onMismatch="DENY" />
                </Filters>
            </AppenderRef>
            <AppenderRef ref="RollingFile">
                <Filters>
                    <Filter type="ThresholdFilter" level="INFO" onMatch="ACCEPT"
                        onMismatch="DENY" />
                </Filters>
            </AppenderRef>
        </Root>
        <AsyncLogger name="org.springframework" level="INFO"
            additivity="false">
            <AppenderRef ref="Console" />
            <AppenderRef ref="RollingFile" />
        </AsyncLogger>
        <AsyncLogger name="org.hibernate" level="INFO"
            additivity="false">
            <AppenderRef ref="Console" />
            <AppenderRef ref="RollingFile" />
        </AsyncLogger>
    </Loggers>
</Configuration>
Alexi answered 27/12, 2018 at 11:29 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.