Hibernate Tips: How to log SQL statements and their parameters


Take your skills to the next level!

The Persistence Hub is the place to be for every Java developer. It gives you access to all my premium video courses, monthly Java Persistence News, monthly coding problems, and regular expert sessions.


Hibernate Tips is a new series of posts in which I describe a quick and easy solution for common Hibernate questions. If you have a question you like me to answer, please leave a comment below.

Question:

How do you configure Hibernate so that it writes the executed SQL statements and used bind parameters to the log file?

Solution:

Hibernate uses 2 different log categories and log levels to log the executed SQL statements and their bind parameters:

  • The SQL statements are written as DEBUG messages to the category org.hibernate.SQL.
  • The bind parameters are logged to the org.hibernate.type.descriptor.sql category with log level TRACE.

You can activate and deactivate them independently of each other in your log configuration.

The following code snippet shows an example of a log4j configuration which activates both of them.

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{HH:mm:ss,SSS} %-5p [%c] - %m%n

log4j.rootLogger=info, stdout
# basic log level for all messages
log4j.logger.org.hibernate=info

# SQL statements and parameters
log4j.logger.org.hibernate.SQL=debug
log4j.logger.org.hibernate.type.descriptor.sql=trace

Hibernate then writes log messages like the following one to your log file.

17:34:50,353 DEBUG [org.hibernate.SQL] - select author0_.id as id1_0_, author0_.firstName as firstNam2_0_, author0_.lastName as lastName3_0_, author0_.version as version4_0_ from Author author0_ where author0_.id=1
17:34:50,362 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1]
17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([firstNam2_0_] : [VARCHAR]) - [Joshua]
17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([lastName3_0_] : [VARCHAR]) - [Bloch]
17:34:50,374 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([version4_0_] : [INTEGER]) - [0]

Further reading:

You can find more information about Hibernates logging features and my recommendation for a development and a production configuration (yes, you should use 2 different ones!) in Hibernate Logging Guide – Use the right config for development and production.

Hibernate Tips Book

Get more recipes like this one in my new book Hibernate Tips: More than 70 solutions to common Hibernate problems.

It gives you more than 70 ready-to-use recipes for topics like basic and advanced mappings, logging, Java 8 support, caching, and statically and dynamically defined queries.

Get it now!

2 Comments

  1. Hello Thorben,

    Is show_sql property not needed to be set to true in addition to making these log4j config changes?

    1. Avatar photo Thorben Janssen says:

      Hi Rashid,

      No, you should never set show_sql to true. It’s slow, ignores your logging configuration and writes the messages to System.out.

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.