No Log4J output in sbt when using scalatest

Question

I'm using Log4J for logging in SBT. In a configuration file, I've defined the TRACE level for the root node. When I run the project (sbt run) all debug output is displayed correctly. But when I run the tests (sbt test), no output at all is generated. I need to insert the class into the configuration to see the output.

The test are written in a JUnit style. Executing the tests with Eclipse shows all Log4J Output. So, it seems to be an issue with SBT or scalatest.

Log4J Configuration:

<?xml version="1.0" encoding="UTF-8"?> 
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration debug="false" xmlns:log4j="http://jakarta.apache.org/log4j/">

  <appender name="stdout" class="org.apache.log4j.ConsoleAppender">
    <layout class="org.apache.log4j.EnhancedPatternLayout">
      <param name="ConversionPattern" value="%-5r [%-5p] %c: %M - %m%n"/>
    </layout>
  </appender>

  <appender name="asyncApp" class="org.apache.log4j.AsyncAppender">
    <appender-ref ref="fileApp"/>
  </appender>

  <appender name="fileApp" class="org.apache.log4j.FileAppender">
    <param name="File" value="testlog_Compiler"/>
    <param name="Append" value="true" />
    <param name="Threshold" value="ALL"/>
    <layout class="org.apache.log4j.EnhancedPatternLayout">
      <param name="ConversionPattern" value="%d [%-5p] %c: %M - %m%n"/>
    </layout>
  </appender>

  <appender name="fileAppTest" class="org.apache.log4j.FileAppender">
    <param name="File" value="testlog_Tests"/>
    <param name="Append" value="true" />
    <param name="Threshold" value="ALL"/>
    <layout class="org.apache.log4j.EnhancedPatternLayout">
      <param name="ConversionPattern" value="%d [%-5p] %c: %M - %m%n"/>
    </layout>
  </appender>

  <logger name="main.Main$" additivity="true">
    <level value="INFO" /> 
  </logger>
<!--
  <logger name="compile.Compiler" additivity="true">
    <level value="DEBUG" />
  </logger>
-->
  <logger name="test" additivity="false">
    <level value="TRACE" />
    <appender-ref ref="stdout"/>
    <appender-ref ref="fileAppTest"/>
  </logger>

  <root>
    <priority value="TRACE"/>
    <appender-ref ref="asyncApp"/>
    <appender-ref ref="stdout"/>
  </root>

</log4j:configuration>

When I use this version of the config file, the tests of compile.Compiler don't generate any log output unless I uncomment its node in the Log4J config. In the SBT configuration file, these dependencies are defined for compile.Compiler: (This is just a minimal example.)

class Comp2011ParentProject(info: ProjectInfo) extends DefaultProject(info) {
    val compiler = project("compile", "compile", new Compile(_))
    class compiler(info: ProjectInfo) extends DefaultProject(info) with Eclipsify {
        val scalatest = "org.scalatest" % "scalatest_2.9.0" % "1.6.1"
        val junitInterface = "com.novocode" % "junit-interface" % "0.6" % "test->default"
        val log4j = "log4j" % "log4j" % "1.2.16"
        val log4jExtras = "log4j" % "apache-log4j-extras" % "1.1"
    }
}

Does anyone have a clue why this happens and how to stop it?

Answer 1

(Unfortunately I lost my account which posted this question. :-( But this is also some kind of answer.)

Further investigations showed that at some point in code the level for the compile.Compiler logger was manually set to INFO. When I delete this statement, everything works fine.

The surprising fact about this is that setting the level in one test also causes all the following tests to adopt that logging level. This was hard to understand because I thought the configuration file was reloaded with every new test.

However, after some documentation surfing, I found out that the actual configuration is not reset when loading a configuration file. To have this behavior a BasicConfigurator.resetConfiguration() must be executed before loading the configuration. With this, everything works as expected.