How to find slow SQL queries with Hibernate or JPA

by

This article will teach you which are the best strategies to detect slow SQL statements when using an ORM such as Hibernate or its Enterprise implementation which is Jakarta Persistence API.

Step 1: Learn how to debug SQL Statements

Data persistence is one of the key factors when it comes to application performance. Therefore, it’s essential to keep track of the performance of your Database statements. First of all, it’s important to stress out that you can log statements emitted by Hibernate through one of the following methods:

1. Adding hibernate.show_sql property to your persistence.xml :

<properties>
    ...
    <property name="hibernate.show_sql" value="true" />
    ...
</properties>

2. Alternatively, if you are using Log4j, you can enable logging of the following categories (using a log4j.properties file here):

log4j.logger.org.hibernate.SQL=DEBUG
log4j.logger.org.hibernate.type=TRACE

3. Then, if you are using WildFly or JBoss EAP, you can create a Logging Handler to debug messages for the org.hibernate.SQL namespace:

/subsystem=logging/periodic-rotating-file-handler=sql_handler:add(level=ALL, file={"path"=>"sql.log"}, append=true, autoflush=true, suffix=.yyyy-MM-dd,formatter="%d{yyyy-MM-dd HH:mm:ss,SSS}")
/subsystem=logging/logger=org.hibernate.SQL:add(use-parent-handlers=false,handlers=["sql_handler"])
/subsystem=logging/logger=org.hibernate.type.descriptor.sql.BasicBinder:add(use-parent-handlers=false,handlers=["sql_handler"])

Finally, WildFly or JBoss EAP users can also choose enabling the spying of SQL statements:

/subsystem=datasources/data-source=ExampleDS/:write-attribute(name=spy,value=true)
/subsystem=logging/logger=jboss.jdbc.spy/:add(level=DEBUG)

This is covered more in detail in this article: How to trace JDBC statements with JBoss and WildFly

Step 2: Log slow SQL Statements

Besides logging SQL statements, since Hibernate 5.4.5 a new property named hibernate.session.events.log.LOG_QUERIES_SLOWER_THAN_MS can be used to display queries which are slower than a particular threshold (in ms.). This property can be added in your persistence.xml file as follows:

<properties>
    ...
    <property name="hibernate.session.events.log.LOG_QUERIES_SLOWER_THAN_MS" value="10"/>
    ...
</properties>

When a SQL query is slower than the threshold ( 10 ms in our example), the Console will print an INFO Message

hibernate / JPA log slow queries

To log slow queries to separate file, please configure logging like:

/subsystem=logging/periodic-rotating-file-handler=slow_sql_handler:add(level=INFO, file={"path"=>"slowsql.log"}, append=true, autoflush=true, suffix=.yyyy-MM-dd,formatter="%d{yyyy-MM-dd HH:mm:ss,SSS}")
/subsystem=logging/logger=org.hibernate.SQL_SLOW:add(use-parent-handlers=false,handlers=["slow_sql_handler"])

As this feature requires Hibernate version 5.4.5, if your application server does not support that version yet, the recommended option is to bundle the latest Hibernate version in your application so that you will override the default version of it.

Conclusion

This article was a walk through some of the common configuration parameters that you can include in your application to find slow SQL queries when using Hibernate or JPA