Java Ninja Chronicles By Norris Shelton

Things I learned in the pursuit of code

In a previous logback blog entry Hibernate Logging (e.g. JBOSS logging) I showed how to send the JBoss logging to your logback logging configuration.

One thing kept bothering me. If you turned on showSql, these were not captured by your logging. I was fishing through the code and discovered why. If you turn on showSql, it actually sets a variable named logToStdout. Just as the name says, in the code, it logs to STDOUT.

if ( logToStdout ) {
	System.out.println( "Hibernate: " + statement );

This results in logging like the following:

Hibernate: insert into cam_affiliate (Channel_ID, Name, Affiliate_ID) values (?, ?, ?)

Logging Sql statements via Logback

A better way is to NOT set showSql to true, but to add the following logger to your Logback configuration.

<!-- Displays the Hibernate SQL statements in your log instead of STDOUT like showSql does-->
<logger name="org.hibernate.SQL" level="DEBUG"/>

This displays logging similar to:

2016-02-19 09:09:30|DEBUG|insert into cam_affiliate (Channel_ID, Name, Affiliate_ID) values (?, ?, ?) ||org.hibernate.engine.jdbc.spi.SqlStatementLogger:92 

February 19th, 2016

Posted In: hibernate, hibernate logging, Java, java ninja, Javaninja, jboss logging, jcl-over-slf4j, log4j-over-slf4j, logback, Logging, Logging configuration, slf4j

Leave a Comment

I was getting the following debug logging, even though my logging config said info and above.

15:14:02.541|DEBUG|RdbmsOperation with SQL [p_select_validate_pin_person_token] compiled||org.springframework.jdbc.object.RdbmsOperation:344
15:14:02.541|DEBUG|Compiled stored procedure. Call string is [{call p_select_validate_sso_person_token(?, ?)}]||org.springframework.jdbc.object.SqlCall:154
15:14:02.541|DEBUG|RdbmsOperation with SQL [p_select_validate_sso_person_token] compiled||org.springframework.jdbc.object.RdbmsOperation:344
15:14:02.542|DEBUG|Compiled stored procedure. Call string is [{call p_delete_truncate(?)}]||org.springframework.jdbc.object.SqlCall:154
15:14:02.542|DEBUG|RdbmsOperation with SQL [p_delete_truncate] compiled||org.springframework.jdbc.object.RdbmsOperation:344
15:14:02.543|DEBUG|Compiled stored procedure. Call string is [{call p_update_setting_inprogress(?)}]||org.springframework.jdbc.object.SqlCall:154

During my research, I learned that Hibernate is logged via JBoss Logging. It used to require a properties file that denoted which logging implementation to use. It now will try to use several logging frameworks, such as commons-logging, log4j and logback. I use Logback.

One common problem is that if you are pulling in lots of dependent libraries, it isn’t uncommon to have multiple logging APIs preset. That was the case that I had.

I checked my dependencies and discovered that I had libraries for:

  • logback-classic – logback is my preferred logging framework.
  • commons-logging – this is the culprit. The JBoss logging API is finding this framework, but isn’t finding a configuration file so everything is being logged.
  • jboss-logging – this is the jboss logging api and is required
  • log4j-over-slf4j – this is the slf4j implementation of the log4j api. In essence, hijacking log4j and funnelling the log4j logging events through slf4j.

To fix this, I had to find every Maven dependency that has a transitive dependency on commons-logging and exclude commons-logging. An example of something that had commons-logging as a transitive dependency was spring-webmvc. I modified the dependency by adding exclusions.


Once I removed all commons-logging transitive dependencies, I had to provide a suitable substitute. This is where another SLF4j dependency comes in handy. This is a SLF4J implementation of the commons-logging api which funnels all of the commons-logging events to my slf4J implementation.


December 30th, 2014

Posted In: hibernate, hibernate logging, java ninja, Javaninja, jboss, jboss logging, jcl-over-slf4j, log4j-over-slf4j, logback, Logging, slf4j

Tags: , , , , , , , , , ,


We wanted to default logging of all messages to warning and above for libraries that we used. We wanted our code to be logged at the info level and above. There was one specific library class that was logging a warning message that was causing confusion to the junior members of the team. Here is what my logback.xml contains.

  • Line 9 – log classes under the com.cdi package at the info level and above
  • Line 11 – log this specific class at the error level and above
  • Line 13 – default logging of the standard out appender to warnings and above
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm:ss.SSS}|%-5level|%msg||%class:%line %xException{full} %n</Pattern>

    <logger name="com.cdi" level="INFO"/>
    <!--Don't show the warning message for no ViewResolvers-->
    <logger name="org.springframework.web.servlet.view.ContentNegotiatingViewResolver" level="ERROR"/>

    <root level="WARN">
        <appender-ref ref="STDOUT"/>

December 30th, 2014

Posted In: appender, appender configuration, java ninja, Javaninja, logback, Logging, Logging configuration, slf4j

Tags: , , , , , , ,

Leave a Comment

Logging is needed, but all of the different frameworks makes this a pain. You are trying to research a problem and you have to bounce from log to log to research it.

SLF4J has bridge implementations that delegate to SLF4J APIs for commons-logging, log4j and even jdk logging.

You need to include the dependency for the logging API that you want to hijack as provided so they will not be packaged, then include the SLF4J bridge api. Repeat for each logging API you want to hijack, then include a SLF4J logging implementation, then away you go.

Here is how to hijack log4j

        <!--hijack log4j-->
        <!--NOTE Saying it is provided so it will not be packaged in my builds if a dependency is using it-->

There are 3 strains of log4j (1.2, 1.3 & 2.0). None are compatible with any of the other. Luckily, only 1.2 is commonly used.

Here is how to hijack commons-logging

        <!--hijack commons logging-->

There is also a jcl104-over-slf4j for commons-logging 1.0.x. I tried to be slick and include that on a project and it got ugly. Those versions of the commons-logging API must not be compatible.

I usually don’t hijack the jdk logging because I rarely encounter it.

All that is remaining is to include a SLF4J implementation. There is one for commons-logging and log4j, but my preferred solution is logback.

        <!-- LogBack -->

This is what works for me, but I see where there could be problems. The logging APIs that I am hijacking are in the compile classpath, but not in the deploy classpath. It could be possible to use Maven exclusions to totally strip out the artifacts, but you must put an exclusion on each dependency that uses the artifact. Good luck keeping up with that. They are supposed to fix this in maven 3.1

February 3rd, 2011

Posted In: Java, logback, slf4j

Tags: , , , , , , , ,

Leave a Comment

WP to LinkedIn Auto Publish Powered By :