Level.ALL deprecation caused us issues

[mikebell90]

In theory switching everything in our library files to Level.Trace should have worked. And it did - kind of.
We notice suddenly all trace level things were logging - which with our general logback file (this is shared during docker builds) should not have been

We believe (and are going to test)

   <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ALL</level>
      <onMatch>DENY</onMatch>
      <onMismatch>NEUTRAL</onMismatch>
    </filter>

Is the culprit and changing to

   <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>TRACE</level>
      <onMatch>DENY</onMatch>
      <onMismatch>NEUTRAL</onMismatch>
    </filter>

will work. But here's the problem

We share common config on a java version basis. So the logback file will be used for all of our java21 usage for example. We don't have different logback.xml for different logback versions. So older logbacks will also change over to this, but the core libraries will still use Level.All

I predict a mess, though we'll see in the next few days. Not sure of what can be done

Summary:

1. Changing core libraries to Level.TRACE led to over logging, because shared logback.xml file bases filter on ALL
2. We could change logback.xml to TRACE, but older core libraries would remain on Level.ALL so I think get the same problem
3. So I think we are "stuck" on Level.ALL for both, which seems... messy

[mikebell90]

I did more investigating.

Here is the specific use case.

1. We have regular logging events and access log events (these are a subclass of our own class RequestLogEvent.

2. There are multiple appenders - one for console, two for file (application, request), one for kafka, configured in a logback file.

3. We want the RequestLogEvent logged only to the request log, not the others

The current implementation is a bit goofy but has worked until now. Basically the non request log appenders all have a LevelFilter for Level = ALL, match=Deny, mismatch=Neutral. The request log otoh has a LevelFilter of Level=ALL, match=neutral, mismatch=deny. The RequestLogEvent is tagged as Level=All

Now I could write my own filter. I did. It is much more sane and it works - basically just checks the class of the logging event. However that would BREAK for older users of our logback file - which is shipped separately. Currently most solutions reaquire us shipping something that

1. Applies the above logic
2. Requires only the replacement of the logback file.
3. The same logback file must work for older logback (1.3, 1.4) and newer without them updating libraries

[mikebell90]

@ceki do you have any suggestions? Below is the current logback file in case the description isnt helpful

I think Level.All used this way is pretty dubious but replacing it seamlessly is the trick given the older clients.

<?xml version="1.0" encoding="UTF-8" ?>
<configuration threshold="TRACE">
  <property scope="context" name="LOG_DIR" value="${MESOS_SANDBOX:-.}/logs" />

  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ALL</level>
      <onMatch>DENY</onMatch>
      <onMismatch>NEUTRAL</onMismatch>
    </filter>
    <encoder>
      <pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS'Z'} %-5p &lt;%X{request-id}&gt; [%t] %logger{36} - %msg %marker%n</pattern>
    </encoder>
  </appender>

  <!-- Rolling access log -->
  <appender name="ACCESS" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ALL</level>
      <onMatch>NEUTRAL</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- hourly rollover -->
      <fileNamePattern>${LOG_DIR}/access.%d{yyyy-MM-dd-HH}.${LOG_EXT:-log.gz}</fileNamePattern>

      <!-- keep LOG_HISTORY (defaults to 6) hours' worth of history -->
      <maxHistory>${LOG_HISTORY:-6}</maxHistory>
    </rollingPolicy>

    <encoder>
      <pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS'Z'} &lt;%X{request-id}&gt; [%t] %msg%n</pattern>
    </encoder>
  </appender>

  <!-- Rolling application log -->
  <appender name="APP" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ALL</level>
      <onMatch>DENY</onMatch>
      <onMismatch>NEUTRAL</onMismatch>
    </filter>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- hourly rollover -->
      <fileNamePattern>${LOG_DIR}/application.%d{yyyy-MM-dd-HH}.${LOG_EXT:-log.gz}</fileNamePattern>

      <!-- keep LOG_HISTORY (defaults to 6) hours' worth of history -->
      <maxHistory>${LOG_HISTORY:-6}</maxHistory>
    </rollingPolicy>

    <encoder>
      <pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSS'Z'} %-5p &lt;%X{request-id}&gt; [%t] %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

  <appender name="KAFKA" class="com.po.logging.KafkaAppender">
    <encoder class="com.po.logging.JsonLogEncoder" />
    <brokerList>${LOGGING_KAFKA_URLS:-${BROKER_LIST}}</brokerList> <!-- This is set in ENV-*/jvm.properties -->
    <topic>${LOG_TOPIC:-logstash}</topic>
    <clientId>${TASK_REQUEST_ID:-${OT_APP}}-${INSTANCE_NO:-0}-${TASK_HOST:-${HOSTNAME}}</clientId>
  </appender>

  <appender name="ASYNC-KAFKA" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="KAFKA" />
    <queueSize>4096</queueSize>
    <neverBlock>true</neverBlock>
  </appender>

  <root level="INFO">
    <appender-ref ref="CONSOLE" />
    <appender-ref ref="APP" />
    <appender-ref ref="ACCESS" />
    <appender-ref ref="ASYNC-KAFKA" />
  </root>
</configuration>

[ceki]

The use of Level.ALL in a long statement is totally wrong and should never occur. Trying to keep using Level.ALL is incomprehensible to me.

[mikebell90]

I agree . That’s not what I asked though :;

[mikebell90]

To be clear, I'm not defending the old methodology (though I'm curious what you would have advised).

The issue is YES I want to fix it for the future but not break people on older dependency trees (eg older logback etc)

• If JaninoEventEvaluatorFilter hadnt been removed, maybe that would have been an option. That works only on older stuff
• Writing my own IS an option and would work on newer stuff.

I guess I COULD try

• Layering two filters, the old one and the new one.
• Then we have two states: Both load or only old one.
• That should work - at least my initial experiment showed the logging system ignores missing filters, but
• is also inelegant in that the old thing will hard break someday, and I must hope that a) I remember b) it's after anyone using the old library has moved to a newer one.

[ceki]

Your initial comment seems to assume that there was an initial discussion where some context about the problem was established. However, I cannot seem to find an earlier discussion we may have had. Anyway, I am missing the context here.

For example, I cannot imagine a normal setting where the following filter would have any effect:

<filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ALL</level>
      <onMatch>DENY</onMatch>
      <onMismatch>NEUTRAL</onMismatch>
</filter>

unless some developer went out of his way to use Level.ALL in a log statement. If so, how did he/she manage to use Level.ALL in a log statement? If this is in a library, which library is this?

[mikebell90]

So in our Logging library indeed the developer did this

public class RequestLogEvent extends LoggingEvent {

  private static final Object[] NO_ARGS = new Object[0];

  private final HttpV1 payload;

  public RequestLogEvent(HttpV1 payload) {
    this(payload, JsonRequestLog.constructMessage0(payload));
  }

  public RequestLogEvent(HttpV1 payload, String message) {
    super("access", logger(), Level.ALL, message, null, NO_ARGS);
    this.payload = payload;
  }

combined with the logback i posted this ended up basically working this way.

The request log ("acccess") was logged only to the appender for access log. All other logging were rejected since there was a filter of Level.All, mismatch=Deny
Fr the other appenders (kafka, console, and "applicaion"), the access log was filtered out (Level.all, match=Deny) and others were allowed

I completely agree this was dumb. And wrote my own simpler filter that simply checks the subclass of the event (eg if its RequestLogEvent).

However my issue is backwards compatibolity - this logback filter is shared with a bunch of services that are not yet up to this managed pom version - and hence will not have access to this new filter.

So my question to be clear is

• Is there a better pure logback way that would work with logback 1.3 through the current that can be expressed only in logback xml terms and doesn't require a time machine ; )

[mikebell90]

In the end the answer might be "no", in which case my plan is to merge my filter unused, and activate it for java25+ (we store our config per java version). The only fly in the ointment would be if you remove Level.All in the currently used logback (1.5.x) series we support for Java 21 until 2028/2029. [Java 17 will be sunsetted at end of 2025] And a cve or such requires an update.

It's convoluted I know, and I apologize

[ceki]

I cannot think of any solution which would not require writing some custom code.

[mikebell90]

Ok thanks. We'll try to figure out something to dig us out of our tech debt. Thanks for the response and for your great library efforts.