JBoss – Spring JDBC SQL logging (log4j)

You might occasionally need to investigate your application on a customer site (or even in your development environment look at parts of the application you’re not familiar with) from the outside first to see what they do in terms of SQL statements, before diving into the code.

Obviously a solution is to trace the statements at database level, but some databases make it easier than others or might require profiling rights and so on. But what you might have access to is your application log4j configuration.

Here’s an example on how to enable SQL logging for Spring JDBC into a separate file appender.

Note that I defined the loggers so they don’t inherit the appenders from parent packages or the root appenders (additivity=”false”) – you can remove that and they will append to predefined appenders as well as this new one. Whenever finished you can raise the level for those two loggers back to WARN to stop the logging, and if you need to leave it on for longer, see the previous post on how to roll logs. It’s probably not recommended though leaving the SQL logging on in production as it might slow the application or will produce large logs in busy environments.

<appender name="FILE_SQL" class="org.jboss.logging.appender.RollingFileAppender">
   <param name="File"      value="${jboss.server.home.dir}/log/sql.log"/>
   <param name="Threshold" value="TRACE"/>
   <param name="Encoding"  value="UTF-8" />

   <layout class="org.apache.log4j.PatternLayout">
     <param name="ConversionPattern" value="%d %-5p (%t) [%c:%L] %m%n"/>
   </layout>        
</appender>

[…]

<!-- SQL logging -->
<logger name="org.springframework.jdbc.core.JdbcTemplate" additivity="false">
  <priority   value="DEBUG"/>
  <appender-ref ref="FILE_SQL"/>
</logger>

<logger name="org.springframework.jdbc.core.StatementCreatorUtils" additivity="false">
  <priority   value="TRACE"/>
  <appender-ref ref="FILE_SQL"/>
</logger>

Sample output:

2012-11-13 16:51:01,969 DEBUG (http-8080-Processor18) [org.springframework.jdbc.core.JdbcTemplate:569] Executing prepared SQL statement [SELECT id, first_name, last_name, address, city, telephone FROM owners WHERE last_name like ?]
2012-11-13 16:51:01,973 TRACE (http-8080-Processor18) [org.springframework.jdbc.core.StatementCreatorUtils:206] Setting SQL statement parameter value: column index 1, parameter value [Doe%], value class [java.lang.String], SQL type unknown