qos-ch / logback

The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch
Other
2.97k stars 1.28k forks source link

Conditional expressions evaluated in a weird order causing configuration discrepancies #829

Open ecourreges-orange opened 1 month ago

ecourreges-orange commented 1 month ago

Hello, I will show you two configurations, one that works, one that doesn't, and maybe you understand what is wrong.
If it's not a bug, this requires at least clear documentation warnings on conditionals.

In all cases i have SYSLOG_HOST = localhost in my environment, because I want my UdpJsonAppender to always work to have remote logs, and I want to activate logs on the file system only on dev environments

This first logback.xml works for all combinations of API_LOGS_FS_ENABLED, API_LOGS_TXT_ENABLED: specifically If these two variables are false, I have my last UdpJsonAppender working on the root logger, and the JsonAppender and TextAppender create empty files which are never filled, I guess this is expected.

<?xml version="1.0" encoding="UTF-8"?>
 <configuration
  scan="{{API_SCAN_LOG_CONF | default("false")}}"
  scanPeriod="{{API_SCAN_LOG_CONF_PERIOD | default("30 seconds")}}"
  debug="{{API_LOG_CONF_DEBUG | default("false")}}">

  <variable name="TOMCAT_LOGS_DIR" value="{{TOMCAT_LOGS_DIR | default("/ var/ log/" ~ API_NAME ~ "/ apache-tomcat/ log")}}" />
  <variable name="API_LOGS_FS_ENABLED" value="{{API_LOGS_FS_ENABLED | default(" false")}}" />
  <variable name="API_LOGS_TXT_ENABLED" value="{{API_LOGS_TXT_ENABLED | default(" false")}}" />
  <variable name="API_LOGS_PREFIX" value="ws" />
  <variable name="API_LOGS_JSON_SUFFIX" value="log.json" />
  <variable name="API_LOGS_TXT_SUFFIX" value="log.txt" />
  <variable name="API_LOG_LEVEL" value="{{API_LOG_LEVEL | default(" WARN")}}" />

  <appender name="JsonAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.${API_LOGS_JSON_SUFFIX}</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.%d{yyyy-MM-dd}.${API_LOGS_JSON_SUFFIX}</fileNamePattern>
      <maxHistory>{{API_LOG_MAX_HISTORY | default(1)}}</maxHistory>
      <totalSizeCap>{{API_LOG_TOTAL_SIZE_CAP | default("100MB")}}</totalSizeCap>
    </rollingPolicy>
    <append>true</append>
    <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
      <providers>
        <timestamp />
        <version />
        <logLevel />
        <threadName />
        <loggerName />
        <message />
        <mdc>
          <fieldName>mdc</fieldName>
        </mdc>
        <stackTrace>
          <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
            <maxDepthPerThrowable>{{API_LOG_STACKTRACES_DEPTH | default(1)}}</maxDepthPerThrowable>
          </throwableConverter>
        </stackTrace>
      </providers>
    </encoder>
  </appender>

  <appender name="TextAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.${API_LOGS_TXT_SUFFIX}</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>
        ${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.%d{yyyy-MM-dd}.%i.${API_LOGS_TXT_SUFFIX}.gz</fileNamePattern>
      <maxFileSize>{{API_LOG_MAX_FILE_SIZE | default("100MB")}}</maxFileSize>
      <maxHistory>{{API_LOG_MAX_DAYS_HISTORY | default(2)}}</maxHistory>
      <totalSizeCap>{{API_LOG_MAX_TOTAL_SIZE | default("200MB")}}</totalSizeCap>
    </rollingPolicy>
    <append>true</append>
    <encoder>
      <pattern>%boldWhite(%d{HH:mm:ss.SSS}) [%thread] %highlight(%-5level) %green(%logger{36}) -
        %.-{{API_LOG_MSG_MAX_LENGTH | default(256)}}msg%n %ex{{'{'}}{{API_LOG_STACKTRACES_DEPTH |
        default(2)}}{{'}'}}</pattern>
    </encoder>
  </appender>

  <if condition="${API_LOGS_TXT_ENABLED}">
    <then>
      <include file="${API_CONF_DIR}/logback-inc-txt.xml" />
    </then>
  </if>

  <appender name="UdpJsonAppender" class="net.logstash.logback.appender.LogstashUdpSocketAppender">
    <host>{{SYSLOG_HOST | default("localhost")}}</host>
    <port>{{SYSLOG_PORT | default(514)}}</port>
    <layout class="com.orange.skeleton.logback.util.SyslogLayout">
      <senderHost>{{SYSLOG_API_SENDER_HOST | default(API_NAME ~ "_host")}}</senderHost>
      <appName>{{SYSLOG_API_WS_APP_NAME | default("app." ~ API_NAME ~ ".ws")}}</appName>
      <maxSize>{{SYSLOG_MESSAGE_MAX_SIZE | default(65000)}}</maxSize>
      <payloadLayout class="net.logstash.logback.layout.LoggingEventCompositeJsonLayout">
        <providers>
          <timestamp />
          <version />
          <logLevel />
          <threadName />
          <loggerName />
          <message />
          <mdc>
            <fieldName>mdc</fieldName>
          </mdc>
          <stackTrace>
            <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
              <maxDepthPerThrowable>{{API_LOG_STACKTRACES_DEPTH | default(1)}}</maxDepthPerThrowable>
            </throwableConverter>
          </stackTrace>
        </providers>
      </payloadLayout>
    </layout>
  </appender>

  <root level="${API_LOG_LEVEL}">
    <if condition="${API_LOGS_FS_ENABLED}">
      <then>
        <appender-ref ref="JsonAppender" />
      </then>
    </if>
    <if condition="${API_LOGS_TXT_ENABLED}">
      <then>
        <appender-ref ref="TextAppender" />
      </then>
    </if>
    <if condition='isDefined("SYSLOG_HOST")'>
      <then>
        <appender-ref ref="UdpJsonAppender" />
      </then>
    </if>
  </root>

  <include file="${API_CONF_DIR}/logback-inc-api.xml" optional="{{API_LOGBACK_INCLUDED_OPTIONAL | default("true")}}" />
  <include file="${API_CONF_DIR}/logback-test.xml" optional="true" />

</configuration>

Whereas in this one, the UdpJsonAppender works only if API_LOGS_FS_ENABLED, API_LOGS_TXT_ENABLED are both true, which is totally unexpected, and makes me think that the root logger evaluates the last if condition only if the appender-ref of JsonAppender and TextAppender are valid, which in this case they are not since their block is also enclosed in a conditional which is false, so the appenders are never declared, but the ifs inside the root are also false so they should be ignored and the one for UdpJsonAppender should still be OK.

This one would have the clear advantage of not creating the resources or the file for the unused appenders, but in practice, it doesn't work.

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

<!-- For assistance related to logback-translator or configuration  -->
<!-- files in general, please contact the logback user mailing list -->
<!-- at http://www.qos.ch/mailman/listinfo/logback-user             -->
<!--                                                                -->
<!-- For professional support please see                            -->
<!--    http://www.qos.ch/shop/products/professionalSupport         -->
<!--                                                                -->
<configuration
  scan="{{API_SCAN_LOG_CONF | default("false")}}"
  scanPeriod="{{API_SCAN_LOG_CONF_PERIOD | default("30 seconds")}}"
  debug="{{API_LOG_CONF_DEBUG | default("false")}}">

  <variable name="TOMCAT_LOGS_DIR" value="{{TOMCAT_LOGS_DIR | default("/var/log/" ~ API_NAME ~ "/apache-tomcat/log")}}" />
  <variable name="API_LOGS_FS_ENABLED" value="{{API_LOGS_FS_ENABLED | default("false")}}" />
  <variable name="API_LOGS_TXT_ENABLED" value="{{API_LOGS_TXT_ENABLED | default("false")}}" />
  <variable name="API_LOGS_PREFIX" value="ws" />
  <variable name="API_LOGS_JSON_SUFFIX" value="log.json" />
  <variable name="API_LOGS_TXT_SUFFIX" value="log.txt" />
  <variable name="API_LOG_LEVEL" value="{{API_LOG_LEVEL | default("WARN")}}" />

  <if condition="${API_LOGS_FS_ENABLED}">
    <then>
      <appender name="JsonAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.${API_LOGS_JSON_SUFFIX}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
          <fileNamePattern>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.%d{yyyy-MM-dd}.${API_LOGS_JSON_SUFFIX}</fileNamePattern>
          <maxHistory>{{API_LOG_MAX_HISTORY | default(1)}}</maxHistory>
          <totalSizeCap>{{API_LOG_TOTAL_SIZE_CAP | default("100MB")}}</totalSizeCap>
        </rollingPolicy>
        <append>true</append>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
          <providers>
            <timestamp/>
            <version/>
            <logLevel/>
            <threadName/>
            <loggerName/>
            <message/>
            <mdc><fieldName>mdc</fieldName></mdc>
            <stackTrace>
              <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                <maxDepthPerThrowable>{{API_LOG_STACKTRACES_DEPTH | default(1)}}</maxDepthPerThrowable>
              </throwableConverter>
            </stackTrace>
          </providers>
        </encoder>
      </appender>
    </then>
  </if>

  <if condition="${API_LOGS_TXT_ENABLED}">
    <then>
      <appender name="TextAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.${API_LOGS_TXT_SUFFIX}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
          <fileNamePattern>${TOMCAT_LOGS_DIR}/${API_LOGS_PREFIX}.%d{yyyy-MM-dd}.%i.${API_LOGS_TXT_SUFFIX}.gz</fileNamePattern>
          <maxFileSize>{{API_LOG_MAX_FILE_SIZE | default("100MB")}}</maxFileSize>
          <maxHistory>{{API_LOG_MAX_DAYS_HISTORY | default(2)}}</maxHistory>
          <totalSizeCap>{{API_LOG_MAX_TOTAL_SIZE | default("200MB")}}</totalSizeCap>
        </rollingPolicy>
        <append>true</append>
        <encoder>
          <pattern>%boldWhite(%d{HH:mm:ss.SSS}) [%thread] %highlight(%-5level) %green(%logger{36}) - %.-{{API_LOG_MSG_MAX_LENGTH | default(256)}}msg%n %ex{{'{'}}{{API_LOG_STACKTRACES_DEPTH | default(2)}}{{'}'}}</pattern>
        </encoder>
      </appender>

      <include file="${API_CONF_DIR}/logback-inc-txt.xml" />
    </then>
  </if>

  <if condition='isDefined("SYSLOG_HOST")'>
    <then>
      <appender name="UdpJsonAppender" class="net.logstash.logback.appender.LogstashUdpSocketAppender">
        <host>{{SYSLOG_HOST | default("localhost")}}</host>
        <port>{{SYSLOG_PORT | default(514)}}</port>
        <layout class="com.orange.skeleton.logback.util.SyslogLayout">
          <senderHost>{{SYSLOG_API_SENDER_HOST | default(API_NAME ~ "_host")}}</senderHost>
          <appName>{{SYSLOG_API_WS_APP_NAME | default("app." ~ API_NAME ~ ".ws")}}</appName>
          <maxSize>{{SYSLOG_MESSAGE_MAX_SIZE | default(65000)}}</maxSize>
          <payloadLayout class="net.logstash.logback.layout.LoggingEventCompositeJsonLayout">
            <providers>
              <timestamp/>
              <version/>
              <logLevel/>
              <threadName/>
              <loggerName/>
              <message/>
              <mdc><fieldName>mdc</fieldName></mdc>
              <stackTrace>
                <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
                  <maxDepthPerThrowable>{{API_LOG_STACKTRACES_DEPTH | default(1)}}</maxDepthPerThrowable>
                </throwableConverter>
              </stackTrace>
            </providers>
          </payloadLayout>
        </layout>
      </appender>
    </then>
  </if>

  <root level="${API_LOG_LEVEL}">
    <if condition="${API_LOGS_FS_ENABLED}">
      <then>
        <appender-ref ref="JsonAppender" />
      </then>
    </if>
    <if condition="${API_LOGS_TXT_ENABLED}">
      <then>
        <appender-ref ref="TextAppender" />
      </then>
    </if>
    <if condition='isDefined("SYSLOG_HOST")'>
      <then>
        <appender-ref ref="UdpJsonAppender" />
      </then>
    </if>
  </root>

  <include file="${API_CONF_DIR}/logback-inc-api.xml" optional="{{API_LOGBACK_INCLUDED_OPTIONAL | default("true")}}" />
  <include file="${API_CONF_DIR}/logback-test.xml" optional="true" />

</configuration>
ceki commented 1 month ago

@ecourreges-orange Thank you for this report. Which version of logback are you using?

ecourreges-orange commented 1 month ago

@ecourreges-orange Thank you for this report. Which version of logback are you using?

logback-classic 1.5.5

ecourreges-orange commented 1 month ago

With logstash-logback-encoder 6.6