Featured Image with Sidebar

How to activate Hibernate Statistics to analyze performance issues

By Thorben Janssen

Configuration, Query

Did you ever ask yourself why a server request took ages on the production system while your local test system was just fine?
Well, we all had these situations and we will have several more of them in the future. In my experience, strange performance drops are often related to slow database queries. But which query causes the problem? And how to find it, if you can’t or don’t want to activate logging on your database?

The good news is, there is an easy way to do it. Hibernate can be configured to collect statistics and to provide the required information to analyze the database queries. So let’s see what we need to do.

Demo application

Let’s begin with a simple demo application. I know your production code is way more complex, but we only need a few database requests for our statistics. Therefore we will use a Product entity with an ID, a version, and a name.

We use this in a loop to store 10 records in the database and query them afterward.

Configuration

The first thing we need to do is tell Hibernate to generate statistics for us. Therefore we need to set the system property hibernate.generate_statistics to true. Statistics are deactivated by default because it has a bad influence on the performance. So only activate them when you need them.

Now Hibernate will write one multi-line log statement with summarized statistical information at the end of the session. This is quite useful to get an overview of how much time was spend on database communication. But in most cases, we need more information. We need to know, if there was a specific query that took a long time or if we have an overall performance issue. Therefore we would like to log the execution time for each query. This can be done by setting the log level for org.hibernate.stat to DEBUG.

Log output

If we execute the test code to store 10 Product entities in the database and read them from the database afterward, Hibernate writes the following log messages:

As you can see, the specific statistics for the select statement and the overall session statistics were written to the log file.

The statistics of the select statement show the number of returned rows (10) and the execution time of the statement (0ms). This would be the place where we would identify a slow statement. But there is obviously no performance issue with this simple query 😉

The overall statistics provide information about the number of used JDBC connections and statements, the cache usage, and the performed flushes. Here you should always check the number of statements first. Lots of performance issues are caused by n+1 select issues that can result in lots of additional queries. You can find more information about how to fix this kind of issues here: 5 ways to initialize lazy relations and when to use them.

If you wonder why Hibernate used 21 instead of 11 JDBC statements to store 10 Product entities and read all of them afterward, you need to set org.hibernate.SQL to DEBUG to get more information. Hibernate required 2 statements to store each new product in the database because it selected the ID of each entity from a database sequence first and used it to store a fully initialized entity in the database.

Conclusion

If you need to analyze performance issues, Hibernate can collect and log useful statistics about each database query and the whole session. This needs to be activated by setting the system property hibernate.generate_statistics to true and the log level for org.hibernate.stat to DEBUG.

You can then decide if the performance issue is caused by the database communication or by some other part of the system. If it is caused by the database communication, you can see if you need to fix it in your Java code or if you need to contact your database administrator to get more detailed information about your slow queries.

About the author

Thorben is an independent consultant, international speaker, and trainer specialized in solving Java persistence problems with JPA and Hibernate.
He is also the author of Amazon’s bestselling book Hibernate Tips - More than 70 solutions to common Hibernate problems.

Books and Courses

Coaching and Consulting

Leave a Repl​​​​​y

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.

  1. Hi, Thorben!

    Is this parameter taken on-the-fly or server should be restarted?
    hibernate.generate_statistics=true

    Log contains no hibernate info, although log4j.logger.org.hibernate.stat=DEBUG

    Thank you.

  2. Thank you Thorben

    It would be nice that the statistic log and the query statement log are printed out in another file.
    By adding a handler:

    I can log the query statement and time consumption into another file, but the statistic log is still in server.log file.

    Do you have any idea?

    Thank you
    Nam Nguyen

    1. Hi,

      that depends on the logging framework and server that you use.
      You can configure it in the same way as any other log message written by other frameworks.

      Regards,
      Thorben

  3. Thank you Thorben

    Mean time when considering LAZY load objects in Hibernate may lead to performance issue ? Due to it will execute SQL queries when accessing LAZY attributes. Does it has a solution ?

    Thank you
    Amila

  4. When persisting one record, Does Hibernate alwayes execute two queries? One for featching the current id(SELECT statement) and second one for persisting the data(INSERT statement).

    Thank you

  5. Hi Richard,

    thanks for your comment.

    Yes, this is a really useful feature to get a better understanding about Hibernate and the performance issue. You often still need more information from your DBA but you know at least what you're looking for.

{"email":"Email address invalid","url":"Website address invalid","required":"Required field missing"}