Thursday, April 13, 2006

Getting the SQL out of Hibernate

Hibernate is a popular Java Object-Relational mapping tool (as if you didn't already know that!) . For debugging purposes you may want to see the actual SQL, including parameter values, that Hibernate sends to the database. Out of the box you can enable the following log4j config:

<!-- Log the actual Hibernate Query Language (HQL) expression -->
<category name="org.hibernate.impl.SessionImpl">
<priority value="DEBUG"/>

<!-- Log the substitution parameters in the HQL expression -->
<category name="org.hibernate.engine.QueryParameters">
<priority value="DEBUG"/>

which will log something like the following:

[main] DEBUG org.hibernate.impl.SessionImpl - find: select count(*) from ClientDO cc where cc.clientID = ?
[main] DEBUG org.hibernate.engine.QueryParameters - parameters: [1786712]
[main] DEBUG org.hibernate.engine.QueryParameters - named parameters: {}

However, HQL is not the real SQL. For that you need to enable more logging:

<!-- Log the real SQL -->
<category name="org.hibernate.SQL">
<priority value="DEBUG"/>

<!-- Log the parameter substitutions in the SQL statement. Unfortunately logging org.hibernate gives a lot of other junk as well -->
<category name="org.hibernate">
<priority value="DEBUG"/>

which adds something like the following to your log output:

[main] DEBUG org.hibernate.SQL - select count(*) as col_0_0_ from instance_property instancepr0_ where (instancepr0_.value, instancepr0_.value_type)=?
[main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
[main] DEBUG org.hibernate.loader.hql.QueryLoader - bindNamedParameters() /root/u2 -> namespacePath [1]
[main] DEBUG org.hibernate.type.StringType - binding '/root/u2' to parameter: 1
[main] DEBUG org.hibernate.type.IntegerType - binding '9' to parameter: 2
[main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement

What would be really useful would be the ability to log the SQL, including parameters, only if Hibernate throws an exception, insteading of logging all of this other stuff. I must look into implementing that...


Anonymous said...

To log the SQL only in the case of an exception, wrap your commit code with a
try {
} catch(JDBCException e) {
log.debug("Unable to commit the transaction because sql call " + e.getSQL() + " fails");
throw e;

still doesn't show the parameter substitutions unfortunately

tdr said...

This is exactly what I would like to do, however, I have no idea where to put this code? Which file?

tdr said...

Of course as soon as I post a comment, find the answer to my question. Isn't that always the way? Thank you for this informative post.

Kalpesh Soni said...

this is what I am using

Anonymous said...

giving hibernate a debug sql with ? for parameters is about as useful as a horse with no legs!!!
Having to muck around with configs to get it to show the full sql is stupid. Show me a situation where seeing ? is more useful than the actual parameter. No wonder people have a bad impression of hibernate!