Aleksey Novik

About Aleksey Novik

Software developer, Likes to learn new technologies, hang out on stackoverflow and blog on tips and tricks on Java/Javascript polyglot enterprise development.

Spring/Hibernate improved SQL logging with log4jdbc

Hibernate provides SQL logging out of the box, but such logging only shows prepared statements, and not the actual SQL queries sent to the database.

It also does not log the execution time of each query, which is useful for performance troubleshooting. This blog post will go over how to setup Hibernate query logging, and then compare it to the logging that can be obtained with log4jdbc.

The Hibernate query logging functionality

Hibernate does not log the real SQL queries sent to the database. This is because Hibernate interacts with the database via the JDBC driver, to which it sends prepared statements but not the actual queries.

So Hibernate can only log the prepared statements and the values of their binding parameters, but not the actual SQL queries themselves.

This is how a query looks like when logged by Hibernate:

select /* load your.package.Employee */ this_.code, ... 
from employee this_ 
where this_.employee_id=?

TRACE 12-04-2014@16:06:02  BasicBinder - binding parameter [1] as [NUMBER] - 1000

See this post Why and where is Hibernate doing this SQL query? for how to setup this type of logging.

Using log4jdbc

For a developer it’s useful to be able to copy paste a query from the log and be able to execute the query directly in an SQL client, but the variable placeholders ? make that unfeasible.

Log4jdbc in an open source tool that allows to do just that, and more. Log4jdbc is a spy driver that will wrap itself around the real JDBC driver, logging queries as they go through it.

The version linked from this post provides Spring integration, unlike several other log4jdbc forks.

Setting up log4jdbc

First include the log4jdbc-remix library in your pom.xml. This library is a fork of the original log4jdbc:

<dependency>
    <groupId>org.lazyluke</groupId>
    <artifactId>log4jdbc-remix</artifactId
    <version>0.2.7</version>
</dependency>

Next, find in the Spring configuration the definition of the data source. As an example, when using the JNDI lookup element this is how the data source looks like:

<jee:jndi-lookup id="dataSource" 
    jndi-name="java:comp/env/jdbc/some-db" />

After finding the data source definition, rename it to the following name:

<jee:jndi-lookup id="dataSourceSpied" 
    jndi-name="java:comp/env/jdbc/some-db" />

Then define a new log4jdbc data source that wraps the real data source, and give it the original name:

<bean id="dataSource" class="net.sf.log4jdbc.Log4jdbcProxyDataSource" >         
     <constructor-arg ref="dataSourceSpied" />         
     <property name="logFormatter">                    
         <bean class="net.sf.log4jdbc.tools.Log4JdbcCustomFormatter" >
             <property name="loggingType" value="SINGLE_LINE" />
             <property name="margin" value="19" />   
             <property name="sqlPrefix" value="SQL:::" />            
         </bean>            
     </property>     
</bean >

With this configuration, the query logging should already be working. It’s possible to customize the logging level of the several log4jdbc loggers available.

The original log4jdbc documentation provides more information on the available loggers:

  • jdbc.sqlonly: Logs only SQL
  • jdbc.sqltiming: Logs the SQL, post-execution, including timing execution statistics
  • jdbc.audit: Logs ALL JDBC calls except for ResultSets
  • jdbc.resultset: all calls to ResultSet objects are logged
  • jdbc.connection: Logs connection open and close events

The jdbc.audit logger is especially useful to validate the scope of transactions, as it logs the begin/commit/rollback events of a database transaction.

This is the proposed log4j configuration that will print only the SQL queries together with their execution time:

<logger name="jdbc.sqltiming" additivity ="false">             
     <level value="info" />                
 </logger>  
 <logger name="jdbc.resultset" additivity ="false">              
     <level value="error" />        
 </logger>  
 <logger name="jdbc.audit" additivity ="false">
     <level value="error" />        
 </logger>   
 <logger name="jdbc.sqlonly" additivity ="false">              
     <level value="error" />        
 </logger>   
 <logger name="jdbc.resultsettable" additivity ="false">           
     <level value="error" />       
 </logger>           
 <logger name="jdbc.connection" additivity ="false">              
     <level value="error" />        
 </logger>  
 <logger name="jdbc.resultsettable" additivity ="false">            
     <level value="error" />        
 </logger>

Conclusion

Using log4jdbc does simply some initial setup, but once it’s in place it’s really convenient to have. Having a true query log is also useful for performance troubleshooting, as will be described in an upcoming post.

Related Whitepaper:

Functional Programming in Java: Harnessing the Power of Java 8 Lambda Expressions

Get ready to program in a whole new way!

Functional Programming in Java will help you quickly get on top of the new, essential Java 8 language features and the functional style that will change and improve your code. This short, targeted book will help you make the paradigm shift from the old imperative way to a less error-prone, more elegant, and concise coding style that’s also a breeze to parallelize. You’ll explore the syntax and semantics of lambda expressions, method and constructor references, and functional interfaces. You’ll design and write applications better using the new standards in Java 8 and the JDK.

Get it Now!  

Leave a Reply


4 × = thirty two



Java Code Geeks and all content copyright © 2010-2014, Exelixis Media Ltd | Terms of Use | Privacy Policy
All trademarks and registered trademarks appearing on Java Code Geeks are the property of their respective owners.
Java is a trademark or registered trademark of Oracle Corporation in the United States and other countries.
Java Code Geeks is not connected to Oracle Corporation and is not sponsored by Oracle Corporation.

Sign up for our Newsletter

20,709 insiders are already enjoying weekly updates and complimentary whitepapers! Join them now to gain exclusive access to the latest news in the Java world, as well as insights about Android, Scala, Groovy and other related technologies.

As an extra bonus, by joining you will get our brand new e-books, published by Java Code Geeks and their JCG partners for your reading pleasure! Enter your info and stay on top of things,

  • Fresh trends
  • Cases and examples
  • Research and insights
  • Two complimentary e-books