Logger slf4j is not using the logback configured level

Question

Even though I have awarded the bounties to the users below that have attempted to help, the original question remains unanswered. No actual workable solution exists to ensure that the logback.groovy configured logging is honoured within the junit tests. The tests load up the logback config and it does report the correct level and yet still the actual test logging (exclusively through slf4j) is at ANY or TRACE level

I know others have encountered this same problem and it is very annoying when tests for big projects take a lot longer due to console logging being much too verbose. I cannot keep throwing bounties at this question. I hope someone comes up with a good solution that allows the tests logging to be properly configured at different levels through a system property. Then, different configurations can be created for the project so that tests will be able to configured at different logging threshold levels.

My logging is configured by logback through a logback.groovy file

Now, when my Maven POM project that aggregates all other projects starts, it passes them all the System property to set the correct logging level.

However, when the junit tests run, for some reason, the logger does not pick up the correct level even though the test classes static @beforeClass ensure that logback is properly configured.

It is not the Loggers in the tests that are the problem, -- well - yes them too-- , the real problem is that the loggers in the code sections that run (all my programs loggers everywhere) are set to the wrong logging level. They are not picking up what the logging is when the program tests are configured.

However, the projects are reporting the correct when logback initializes with the logback.goovy file. However, the actual logging level is set to TRACE or ALL

From the output below, it is clear that logback has configured to INFO. But the first project logging statement at TRACE (last line) shows that is not being picked up.

Help.

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running groovy.text.StreamingTemplateEngineTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.245 sec
Running net.abcd.templating.InlinerTest
01:22:15,265 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Added status listener of type [ch.qos.logback.core.status.OnConsoleStatusListener]
01:22:15,290 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Setting ReconfigureOnChangeFilter scanning period to 5 minutes
01:22:15,290 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[C:\Users\ABDC\Dropbox\workspace\abcd\AbcdTemplating\conf\logback.groovy]] every 300 seconds. 
01:22:15,290 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Adding ReconfigureOnChangeFilter as a turbo filter
01:22:15,312 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
01:22:15,316 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Naming appender as [STDOUT]
***********************************************************

LOGGING MODE PROPERTY 'net.abcd.logging.level' SET TO: [info]
IT CAN BE SET TO: OFF, ERROR, WARN, INFO, DEBUG, TRACE, ALL, INFO

***********************************************************
getLogLevel() returned 'INFO'
01:22:15,496 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Setting level of logger [ROOT] to INFO
01:22:15,532 |-INFO in ch.qos.logback.classic.gaffer.ConfigurationDelegate@1e8c3cb - Attaching appender named [STDOUT] to Logger[ROOT]
01:22:15.846 [main] TRACE net.abcd.templating.Inliner - Document:

My logback.groovy file is:

displayStatusOnConsole()
scan('5 minutes')  // Scan for changes every 5 minutes.
setupAppenders()
setupLoggers()

def displayStatusOnConsole() {
    statusListener OnConsoleStatusListener 
}

def setupAppenders() {
    appender('STDOUT', ConsoleAppender) {
        encoder(PatternLayoutEncoder) {
            pattern = "%d{HH:mm:ss.SSS} [%thread] %-5level %-16logger{50} - %msg%n"
        }
    }
}


def setupLoggers() {    
    def loglevel = getLogLevel() 
    println("getLogLevel() returned '${loglevel}'")
    root(loglevel, ['STDOUT'])
}

def getLogLevel() {
    def mode = System.getProperty('net.abcd.logging.level', '')
    println("***********************************************************")
    println("")
    println("LOGGING MODE PROPERTY 'net.abcd.logging.level' SET TO: [${mode}]")
    println("IT CAN BE SET TO: OFF, ERROR, WARN, INFO, DEBUG, TRACE, ALL, INFO")
    println("")
    println("***********************************************************")
    switch(mode.toLowerCase()){
    case 'off':
        return OFF
    case 'error':
        return ERROR
    case 'warn':
        return WARN
    case 'info':
        return INFO
    case 'debug':
        return DEBUG
    case 'trace':
        return TRACE
    case 'all':
        return ALL
    default:
        return INFO
    }
}

Answer 1

I met a similar issue on my junit tests as well. I couldn't find a good solution. I used below work around:

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import org.slf4j.LoggerFactory;
...
static Logger logger;
static{
   // Logger.ROOT_LOGGER_NAME == "ROOT"
   logger = ((Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME));
   logger.setLevel(Level.INFO);
}

...

I think in your case, somehow a library uses it's own ConsoleAppender instance whose name is not 'STDOUT'. I hope setting root log level should resolve the issue.

root(loglevel, ['ROOT']);