Log SQL Statements with iBatis

Here's what I've done to enable logging of SQL statements in an iBatis context. This adds to the various bits of advice I've found on the web.

Perhaps it's due to the environment I'm using (Java 1.6, iBatis 2.3.4, SLF4J 1.5.11, Log4J 1.2.15), but the guidance offered in the iBatis Dev Guide is, in my experience, not quite right. In fairness, something must have changed since last I tried that advice (was I using Java 1.5 back then? I'm not sure), since, as I recall, it resulted in the SQL logging I needed. However, at the moment I find that simply configuring this:

<logger name="java.sql.PreparedStatement">
    <level value="debug"/>
</logger>

...yields no SQL output at all.

On target is the advice given in the Apache Bookstore, i.e. to specify this:

<logger name="java.sql">
    <level value="debug"/>
</logger>

This yields all of connection information, prepared statements, values inserted as prepared statement parameters and result sets, something like this:

Connection
{conn-100008} Preparing Statement:  select name, description  from mytable where name like ?      
{pstm-100009} Executing Statement:  select name, description  from mytable  where name like ?               
{pstm-100009} Parameters: [name%]
{pstm-100009} Types: []
{rset-100010} ResultSet
{rset-100010} Header: [NAME, DESCRIPTION]
{rset-100010} Result: [name2, Desc for name2]
{rset-100010} Result: [name3, Desc for name3]

You'll possibly get even more output, depending on your app - since the java.sql namespace is more than just these things. If this is a concern, use the following:

    <logger name="java.sql.Connection">
        <level value="debug"/>
    </logger>

    <logger name="java.sql.PreparedStatement">
        <level value="debug"/>
    </logger>

    <logger name="java.sql.ResultSet">
        <level value="debug"/>
    </logger>

I've personally found that the output from PreparedStatement and ResultSet are the most useful - but omitting Connection appears to preclude these log statements from appearing. The Connection logger also appears to control the output level of PreparedStatement and ResultSet - i.e., setting Connection to INFO results in zero output from any of them. I begin to suspect that Connection has a parent relationship to the other two; perhaps this is what's changed since last I did this.

In either event, here are some SQL-interceptor tools recommended by various posts (though I've yet to try either one):

p6spy: http://www.p6spy.com/
jdbcdslog: http://code.google.com/p/jdbcdslog/

And here are all the web references I used for this post:

Stack Overflow:
http://stackoverflow.com/questions/3014318/how-to-do-ibatis-version-of-show-sql
http://stackoverflow.com/questions/2635058/ibatis-get-executed-sql
Apache Bookstore: http://www.apachebookstore.com/confluence/oss/display/IBATIS/How+do+I+get+SqlMapClient+to+log+SQL+statements
iBatis Dev Guide: http://ibatisnet.sourceforge.net/DevGuide.html#d0e2600

When Log4j Logs Messages Twice...

Since my Google'ing only gave me a clue instead of the complete answer on this one, I post it here for future reference.

When a given logger in a log4j configuration is outputting messages twice to your appender, you might try adding the additivity attribute as a fix:

<logger name="myLogger" additivity="false">
    <level value="info"/>
    <appender-ref ref="myFile"/>
</logger>

Same idea for logger or for category. From the DTD (I'm using version 1.2.15):

<!ELEMENT category (param*,(priority|level)?,appender-ref*)>
<!ATTLIST category
  class         CDATA   #IMPLIED
  name  CDATA #REQUIRED
  additivity (true|false) "true"  
>

<!ELEMENT logger (level?,appender-ref*)>
<!ATTLIST logger
  name  CDATA #REQUIRED
  additivity (true|false) "true"  
>

This worked for me. As you can see, the additivity defaults to true. There may be other fixes, but I didn't dig any further after fixing my problem.