I have a web application configured to use SLF4J and logback for logging. All of the application code logs correctly based on the appenders I have set up in my logback.xml; except Hibernate. For some reason Hibernate initialization is writing DEBUG statements to SysOut and I can't figure out why.
Relevant libraries including in WEB-INF/lib of my war file:
- slf4j-api-1.7.5.jar
- logback-classic-1.0.12.jar
- logback-core-1.0.12.jar
- jboss-logging-3.1.0.GA.jar
- hibernate-jpa-2.0-api-1.0.1.Final.jar
- hibernate-commons-annotations-4.0.2.Final.jar
- hibernate-core-4.2.5.Final.jar
- hibernate-entitymanager-4.2.5.Final.jar
- hibernate-envers-4.2.5.Final.jar
- jcl-over-slf4j-1.7.5.jar
I am running the application on Websphere v8.0.0.8. I have configured Websphere to use parent-last Class-loading so that the libraries in my application will get picked over libraries exposed by the Websphere container.
When the application starts, I see this:
Quote:
[4/3/14 9:45:57:113 CDT] 0000001d SystemOut O 09:45:57.110 [Default : 5] DEBUG org.jboss.logging - Logging Provider: org.jboss.logging.Slf4jLoggerProvider
[4/3/14 9:45:57:207 CDT] 0000001d SystemOut O 09:45:57.207 [Default : 5] DEBUG org.hibernate.type.BasicTypeRegistry - Adding type registration boolean -> org.hibernate.type.BooleanType@fd38007b
[4/3/14 9:45:57:207 CDT] 0000001d SystemOut O 09:45:57.207 [Default : 5] DEBUG org.hibernate.type.BasicTypeRegistry - Adding type registration boolean -> org.hibernate.type.BooleanType@fd38007b
[4/3/14 9:45:57:208 CDT] 0000001d SystemOut O 09:45:57.208 [Default : 5] DEBUG org.hibernate.type.BasicTypeRegistry - Adding type registration java.lang.Boolean -> org.hibernate.type.BooleanType@fd38007b
...
So it looks like jboss logging is (seemingly correctly) picking SLF4J as the provider. However, I do not have a console appender configured nor do I have org.hibernate.* set to DEBUG level.
I have Logback set up to use the ContextJNDISelector and I know the configuration file is being read by setting <configuration debug="true"> in the logback.xml file and was able to see how logback is being configured (nothing seemed off there).
If it helps, here is my logback.xml file:
Code:
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>
%d ${CONTEXT_NAME} [%thread] %-5level %logger{36} - %msg%n
</Pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<FileNamePattern>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging.%i.log.zip
</FileNamePattern>
<MinIndex>1</MinIndex>
<MaxIndex>10</MaxIndex>
</rollingPolicy>
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>100MB</MaxFileSize>
</triggeringPolicy>
</appender>
<appender name="Im" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging-im.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>
%d ${CONTEXT_NAME} [%thread] %-5level %logger{36} - %msg%n
</Pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<FileNamePattern>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging-im.%i.log.zip
</FileNamePattern>
<MinIndex>1</MinIndex>
<MaxIndex>10</MaxIndex>
</rollingPolicy>
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>100MB</MaxFileSize>
</triggeringPolicy>
</appender>
<appender name="In" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging-in.log</file>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>
%d [%thread] %-5level %logger{36} - %msg%n
</Pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<FileNamePattern>logs/${appname.log.dir}/${CONTEXT_NAME}-messaging-in.%i.log.zip
</FileNamePattern>
<MinIndex>1</MinIndex>
<MaxIndex>10</MaxIndex>
</rollingPolicy>
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<MaxFileSize>100MB</MaxFileSize>
</triggeringPolicy>
</appender>
<logger name="ImLogger" level="info" additivity="false">
<appender-ref ref="Im"/>
</logger>
<logger name="InLogger" level="info" additivity="false">
<appender-ref ref="In"/>
</logger>
<root level="info">
<appender-ref ref="FILE" />
</root>
</configuration>
It seems that other people have had this issue but I haven't been able to figure out why this is happening or how to fix it:
https://forum.hibernate.org/viewtopic.php?f=1&t=1030995&hilit=logging
http://stackoverflow.com/questions/18022955/logback-logger-level-ignored-when-logs-come-from-jboss-logging
I do suspect it has something to do with Websphere because I can run the application locally on a Jetty server without experiencing this behavior; but any suggestions or ideas as to why this might happen or where to go from here would be appreciated.