Wednesday, September 8, 2010

Log SQL Statements on Hibernate

Hibernate, in the end, is all about dispatching SQL statements. SQL is at the heart of communication with an RDBMS system, and it is extremely important when struggling through performance problems or other bugs, that you know what is going on. After all, knowing the executed SQL allows you to determine the number of queries to complete an O/R mapping task, not to mention that seeing SQL queries is critical to understanding how to optimize the queries via indices and other database settings.
There are two ways (due to the legacy of Hibernate) to enable SQL logging. The first is to simply enable SQL logging in the Hibernate configuration By setting the hibernate.show_sql to TRUE

This is a nice quick and dirty solution, but it is relatively inflexible. SQL statements are always logged to System.out when that property is enabled, and on some servers, System.out isn't accessible by the average developer; or is cluttered with a million other log statements.

Alternatively, Hibernate uses the Apache-Jakarta Commons Logging package, which means that it will utilize log4j , java.util.logging , or potentially another logging framework. Typically, log messages are sent to commons logging, and then they are dispatched to one of these logging frameworks. Then, those logging frameworks determine where the message should be sent (log files, sockets, emails, database records, system out, system err, etc). It is easy to see how using these log frameworks will increase the flexibility of log statements. With Hibernate, simply setting the org.hibernate.SQL logger to 'DEBUG' or 'ALL' will ensure that all SQL statements are logged to the console.


If you set up a log4j category for org.hibernate.type
Get it to write out to the same log file as the org.hibernate.SQL
The type one will list the parameters for you after the SQL e.g.
2006-07-28 09:57:12,061 DEBUG org.hibernate.SQL - insert into BASKET_LINE_ALLOC (LAST_UPDATED, QUANTITY, CUSTOMER_REF, NOTES, BRANCH_ID, FUND_ID, TEMPLATE_ID, 
BASKET_LINE_ALLOC_ID) values (?, ?, ?, ?, ?, ?, ?, ?) 
2006-07-28 09:57:12,081 DEBUG org.hibernate.type.TimestampType - binding '2006-07-28 09:57:12' to parameter: 1 
2006-07-28 09:57:12,081 DEBUG org.hibernate.type.IntegerType - binding '3' to parameter: 2 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.StringType - binding '' to parameter: 3 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.StringType - binding '' to parameter: 4 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.LongType - binding '511' to parameter: 5 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.LongType - binding '512' to parameter: 6 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.LongType - binding null to parameter: 7 
2006-07-28 09:57:12,082 DEBUG org.hibernate.type.LongType - binding '180030' to parameter: 8 

No comments:

Post a Comment