3

Background

I am using slf4j with Logback as underlying logger.

A system (i.e., a bunch of interoperating classes) can be concurrently used by a client. Each invocation should have its own log file. The log file is provided by the client.

I want to

  • have a separate log file per invocation of the system

  • each invocation should log to its own log file, but not to others

  • The system itself has some concurrent executions

  • The client might concurrently invoke the system multiple times

I can set the log file programmatically, similar to Logback - set log file name programmatically.

Problem

If the system is invoked twice, then the first log file is still bound to the file appender, which results in the second invocation writing to both log files. I can call detachAndStopAllAppenders on the logger, but this causes a potentially concurrent invocation to lose its file appender.

When adding a new File Appender without detaching previously attached appenders:

Subsequent log statements are written to the new file aswell as previously attached files.

When detaching File Appenders and then attaching the new File Appender:

An already running system now logs to the new log file instead of the actual log file.

Problem Origin

If I am not mistaken, the origin of the problem is the static Loggerfactory, i.e., because the system obtains the logger by calling LoggerFactory.getLogger(getClass), the same logger is returned by different invocations. Is there a non-static equivalent to the LoggerFactory? Or how would I solve the problem otherwise?

Ugly Solution

While writing an MWE I came up with an ugly solution that seems to be working. However, this solution requires synchronizing each logging call, detaching the old appender, attaching the new appender, and performing the actual logging. Here's the code in Scala:

package samples

import java.nio.file.{Files, Path}

import ch.qos.logback.classic.LoggerContext
import ch.qos.logback.classic.encoder.PatternLayoutEncoder
import ch.qos.logback.classic.spi.ILoggingEvent
import ch.qos.logback.core.rolling.{SizeBasedTriggeringPolicy, FixedWindowRollingPolicy, RollingFileAppender}
import org.slf4j.LoggerFactory
import org.slf4j.helpers.SubstituteLogger

object SampleLogging {

  def main(args: Array[String]) {
    val sys1 = new Thread(new TheSystem(Files.createTempFile("sys1_",".log")))
    val sys2 = new Thread(new TheSystem(Files.createTempFile("sys2_",".log")))
    sys1.start()
    sys2.start()
    sys1.join()
    sys2.join()
    println("finished")
  }

  class TheSystem(logFile: Path) extends Runnable {
    def run() {
      val logger = new Logger(logFile)
      for (i <- 1 to 1000){
        logger.info(getClass)("Logging to file " + logFile)
      }
    }
  }

  class Logger(logFile: Path) {

    def info(context: Class[_])(msg: String){
      var slf4j = LoggerFactory.getLogger(context)
      while(slf4j.isInstanceOf[SubstituteLogger]){
        slf4j = LoggerFactory.getLogger(context)
      }
      slf4j match {
        case logback: ch.qos.logback.classic.Logger =>
          val appenderConfig = new RollingFileAppenderConfiguration(LoggerFactory.getILoggerFactory.asInstanceOf[LoggerContext])
          logback.synchronized {
            logback.detachAndStopAllAppenders()
            logback.addAppender(appenderConfig.appender)
            logback.info(msg)
          }
      }
    }

    private class RollingFileAppenderConfiguration(context: LoggerContext) {

      val appender: RollingFileAppender[ILoggingEvent] = {
        val rollingFileAppender = new RollingFileAppender[ILoggingEvent]
        rollingFileAppender.setFile(logFile.toAbsolutePath.toString)
        rollingFileAppender.setRollingPolicy(rollingPolicy(rollingFileAppender))
        rollingFileAppender.setTriggeringPolicy(triggeringPolicy)
        rollingFileAppender.setEncoder(encoder)
        rollingFileAppender.setContext(context)
        rollingFileAppender.start()
        rollingFileAppender
      }

      private def rollingPolicy(appender: => RollingFileAppender[ILoggingEvent]) = {
        val fixedWindowRollingPolicy = new FixedWindowRollingPolicy
        fixedWindowRollingPolicy.setFileNamePattern(s"log/${logFile.getFileName}.%i.log.zip")
        fixedWindowRollingPolicy.setMinIndex(1)
        fixedWindowRollingPolicy.setMaxIndex(3)
        fixedWindowRollingPolicy.setParent(appender)
        fixedWindowRollingPolicy.setContext(context)
        fixedWindowRollingPolicy
      }

      private def triggeringPolicy = {
        val sizeBasedTriggeringPolicy = new SizeBasedTriggeringPolicy[ILoggingEvent]
        sizeBasedTriggeringPolicy.setMaxFileSize("5MB")
        sizeBasedTriggeringPolicy.setContext(context)
        sizeBasedTriggeringPolicy
      }

      private def encoder = {
        val patternLayoutEncoder = new PatternLayoutEncoder
        patternLayoutEncoder.setPattern("%date{YYYY-MM-dd HH:mm:ss} %level [%thread] %logger{10} [%file:%line] %msg%n")
        patternLayoutEncoder.setContext(context)
        patternLayoutEncoder.start()
        patternLayoutEncoder
      }
    }
  }
}

I have the feeling that this excessive locking is very bad for performance. Am I wrong? Can I achieve the same without excessive locking?

Community
  • 1
  • 1
Kulu Limpa
  • 3,501
  • 1
  • 21
  • 31

0 Answers0