Grzegorz Grzybek created this issue on 07/Jan/23 11:29 AM

I'm working on Pax Logging project which uses Logback (and Log4j2) as logging backends.

Over time, we've collected quite a number of integration tests, which are quite tricky in OSGi environment, where Pax Exam testing framework itself relies on Pax Logging.

However one of the tests stopped working when upgrading from SLF4J 1.7.36 + Logback 1.2.11 to SLF4J 2.0.6 + Logback 1.3.5.

The configuration is:

  <configuration id="builtin.socket">
      <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
          <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
              <layout class="ch.qos.logback.classic.layout.TTLLLayout" />
          </encoder>
      </appender>
      <appender name="s" class="ch.qos.logback.classic.net.server.ServerSocketAppender">
          <address>localhost</address>
          <!-- System.setProperty("socketAppender.port", Integer.toString(port)); -->
          <port>${socketAppender.port}</port>
          <includeCallerData>true</includeCallerData>
      </appender>
      <logger name="my.logger" level="info" additivity="false">
          <appender-ref ref="s" />
      </logger>
      <root level="info">
          <appender-ref ref="console" />
      </root>
  </configuration>
  

The problem is
https://github.com/qos-ch/logback/commit/fc7c9a440f560260c4 commit, which changes ch.qos.logback.core.CoreConstants#SCHEDULED_EXECUTOR_POOL_SIZE from 8 to
1.

The problem is here:

• ch.qos.logback.core.net.server.AbstractServerSocketAppender#start() creates an instance of ch.qos.logback.core.net.server.RemoteReceiverServerRunner
• the runner is passed to scheduled executor taken from ch.qos.logback.core.Context#getExecutorService()
• ch.qos.logback.core.net.server.ConcurrentServerRunner#run() running in executor's thread is this:

    while (!Thread.currentThread().isInterrupted()) {
        T client = listener.acceptClient();
        if (!configureClient(client)) {
            addError(client + ": connection dropped");
            client.close();
            continue;
        }
        try {
            executor.execute(new ClientWrapper(client));
        } catch (RejectedExecutionException ex) {
            addError(client + ": connection dropped");
            client.close();
        }
    }
    

So every accepted client is passed to the same executor as the server. It works only if the core pools size is greater than 1, because one thread is busy with the server itself. So the only thing that's happening is the growing queue of ch.qos.logback.core.net.server.ConcurrentServerRunner.ClientWrapper tasks.

ch.qos.logback.core.CoreConstants#SCHEDULED_EXECUTOR_POOL_SIZE should be by default at least 2.