Java client / driver not logging debug or trace to SLF4j API

[Brett Cave]

hi mongo devs,

wondering if someone could confirm if I am doing something wrong, or if this is possibly a bug in the mongo driver. I am using the mongo java client in a scala application (using casbah as a java->scala wrapper). The scala application uses the slf4j api (with logback as the logging backend). I am trying to enable mongo query tracing, but am unable to get the trace statements logged.

in my scala application, I set the system property: System.setProperty("DB.TRACE","true") - I do this before initializing the driver.
According to the DBApiLayer source, and http://stackoverflow.com/questions/9545341/configure-logging-for-the-mongodb-java-driver, this should be sufficient to enable trace logging. However, when SLF4j initializes, TRACE_LOGGER.isLoggable returns false:

    // enable tracing
    System.setProperty("DB.TRACE","true")
    // initialize the client
    mongoClient = MongoClient(List(new ServerAddress(host,port),clientOptions))
    // initialize database
    mongoDb = mongoClient(dbName)
    // get an instance of the com.mongodb.TRACE logger and check if it's loggable - this is the same logic used by the willTrace() method in DBApiLayer...
    java.util.logging.Logger.getLogger("com.mongodb.TRACE").isLoggable(java.util.logging.Level.INFO) // returns false
    // workaround: manually set loglevel for the logger, so that isLoggable returns true.
    java.util.logging.Logger.getLogger("com.mongodb.TRACE").setLevel(java.util.logging.Level.INFO) // messages now logged to stdout, no logback config applied.

So I am not able to get trace logs from the Mongo client into my logging framework. I have been able to work around this be manually setting the logger level to INFO after the database & slf4j has been initialized. This results in mongo logging via JUL with a default configuration (i.e. I have no control via logback / log4j configurations, as the messages are not being logged via the slf4j api).

Is there something I am overlooking, or is there another way to configure this?

[Robert Moore]

You will need to use the jul-to-slf4j bridge to get the java.util.logging (jul) messages into the SLF4J framework.

More information (including a performance warning) here: http://www.slf4j.org/legacy.html#jul-to-slf4j

Rob.

[Brett Cave]

On Saturday, 20 July 2013 00:24:15 UTC+2, Robert Moore wrote:

You will need to use the jul-to-slf4j bridge to get the java.util.logging (jul) messages into the SLF4J framework.

More information (including a performance warning) here: http://www.slf4j.org/legacy.html#jul-to-slf4j

I actually did try that before posting to the group, but didn't read the documentation properly. Added the library to the classpath but never called the "install()" method. Helps to RTM properly. Just retried, this time adding SLF4JBridgeHandler.install() with the system property prior to the driver initialization and bridging is working correctly.

Thanks Rob.
 

[Brett Cave]

On Saturday, 20 July 2013 00:24:15 UTC+2, Robert Moore wrote:

You will need to use the jul-to-slf4j bridge to get the java.util.logging (jul) messages into the SLF4J framework.

More information (including a performance warning) here: http://www.slf4j.org/legacy.html#jul-to-slf4j

1 inconsistency with this is the following: if I set the system property DB.TRACE to true, install the SLF4J bridge and then initialize the driver, the JUL logger still returns false for isLoggable. So in my code, once the driver has been initialized, I still need to add in a manual logger level override:

    // assuming bridge has been installed and DB.TRACE has been set to true.
   mongoDB = mongoClient(dbName)
   // at this point, trace logging is not sent to SLF4J with an INFO level.
   java.util.logging.Logger.getLogger("com.mongodb.TRACE").setLevel(java.util.logging.Level.INFO)
   // now trace logs show as expected.

After the manual override, JUL returns true on the isLoggable call. The result is that within the application, mongo trace logging is sent to SLF4, and therefor the logging backend (logback), but also to JUL. The application doesn't have an explicit config for JUL, so while trace logs are sent to the logging configuration, they are also sent to stdout (JUL's default console appender).

I guess this is the expected behaviour....
 

Rob.