%PARSER_ERROR[wex] in spring boot logging

Question

I am getting the following error string occasionally in my log file. I am running a spring cloud application using spring boot. I use a log back configuration file that includes another config file. The spring boot version is v1.2.3 (Spring cloud 1.0.1).

%PARSER_ERROR[wex]2015-06-01 12:30:22.180 DEBUG 6833 --- [http-nio-9000-exec-1] ... rest of log message

I saw this entry (Spring Boot - logback PARSER_ERROR), but ti does not seem applicable.

The logback.xml file is:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <property name="LOG_FILE" value="logs/myservice.log"/>

    <!-- the rollover settings with mean a max size per log of 100Mb and 7 days -->
    <property name="MAX_HISTORY" value="7"/>
    <property name="MAX_FILE_SIZE" value="100MB"/>


    <!-- the specific loggers -->
    <logger name="com.companyx" level="DEBUG"/>
    <logger name="org.springframework" level="ERROR"/>
    <logger name="org.springframework.security.oauth2" level="INFO"/>
    <logger name="org.springframework.integration" level="OFF"/>
    <logger name="org.springframework.oxm" level="OFF"/>
    <logger name="org.springframework.http" level="ERROR"/>

    <logger name="com.netflix.discovery" level="OFF"/>
    <logger name="com.netflix.eureka.util.AwsAsgUtil" level="OFF"/>

    <logger name="com.mangofactory.swagger.scanners" level="OFF"/>

    <include resource="com/companyx/services/common/logging/baselog.xml"/>

</configuration>

The included baselog.xml file is:

<?xml version="1.0" encoding="UTF-8"?>
<included>

    <!-- turn on JMX configuration -->
    <jmxConfigurator />

    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
    <conversionRule conversionWord="wex"
                    converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter"/>

    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS, Zulu}){faint} %clr(%5p) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n%wex"/>
    <property name="FILE_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS, Zulu} %5p ${PID:- } --- [%t] %-40.40logger{39} : %m%n%wex"/>

    <appender name="DEBUG_LEVEL_REMAPPER" class="org.springframework.boot.logging.logback.LevelRemappingAppender">
        <destinationLogger>org.springframework.boot</destinationLogger>
    </appender>

    <logger name="org.apache.catalina.startup.DigesterFactory" level="ERROR"/>
    <logger name="org.apache.catalina.util.LifecycleBase" level="ERROR"/>
    <logger name="org.apache.coyote.http11.Http11NioProtocol" level="WARN"/>
    <logger name="org.apache.sshd.common.util.SecurityUtils" level="WARN"/>
    <logger name="org.apache.tomcat.util.net.NioSelectorPool" level="WARN"/>
    <logger name="org.crsh.plugin" level="WARN"/>
    <logger name="org.crsh.ssh" level="WARN"/>
    <logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="ERROR"/>
    <logger name="org.hibernate.validator.internal.util.Version" level="WARN"/>
    <logger name="org.springframework.boot.actuate.autoconfigure.CrshAutoConfiguration" level="WARN"/>
    <logger name="org.springframework.boot.actuate.endpoint.jmx" additivity="false">
        <appender-ref ref="DEBUG_LEVEL_REMAPPER"/>
    </logger>
    <logger name="org.thymeleaf" additivity="false">
        <appender-ref ref="DEBUG_LEVEL_REMAPPER"/>
    </logger>

    <!-- declare the different appenders -->

    <!-- declare the appender that writes to the console -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

    <!-- declare the appender that writes to the log file -->
    <appender name="FILE"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
        </encoder>
        <file>${LOG_FILE}</file>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.log.gz</fileNamePattern>
            <!-- keep 30 days' worth of history -->
            <maxHistory>${MAX_HISTORY}</maxHistory>
        </rollingPolicy>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>${MAX_HISTORY}</maxHistory>
        </rollingPolicy>

    </appender>


    <!-- default logging levels, unless we overwrite then use INFO-->
    <root>
        <level value="INFO"/>
        <appender-ref ref="FILE"/>
        <appender-ref ref="CONSOLE"/>
    </root>

    <!-- application overrides will be added in files that include this one -->

</included>

Answer 1

Turns out in our case, the issue was in the ELK system we were using. We ran an Elasticsearch-Logstash-Kibana log collection system and the log stash agent collecting the logs was inserting the %PARSER_ERROR%[wex] onto the log record as it was passing it on.

After we got the accepted workaround, problem gone.