Hibernate Show SQL

Hibernate Show SQL

9 Comments

When you are developing Spring Boot applications with database interactions, you typically use Hibernate as the Object Relationship Mapping (ORM) tool.

Instead of directly coupling your code with Hibernate, often you’d rather use Spring Data JPA, a Spring Framework project.

Spring Data JPA makes implementation of the data access layer incredibly easy by abstracting most of the complexities involved in persisting data.

Often when you are working with Hibernate and Spring Data JPA, you will need to see what is happening under the hood. It is very helpful to see the actual SQL statements being generated by Hibernate.

Due to the nature of the abstractions offered by Hibernate and Spring Data JPA, its very easy to inadvertently create n+1 queries; which is VERY detrimental to the performance of your application.

In this post, I’ll share a tip on how to configure Hibernate and Spring Data JPA to log executed SQL statements and used bind parameters.

The Application

For the purpose of this post, I’ve created a simple Spring Boot application. In this application, we can perform CRUD operations on a Product entity.

Here is the Product entity.

Product.java

package guru.springframework.domain;

import javax.persistence.*;
import java.math.BigDecimal;

@Entity
public class Product {
    @Id
    @GeneratedValue(strategy = GenerationType.AUTO)
    private Integer id;
    @Version
    private Integer version;
    private String productId;
    private String description;
    private String imageUrl;
    private BigDecimal price;

    public String getDescription() {
        return description;
    }

    public void setDescription(String description) {
        this.description = description;
    }

    public Integer getVersion() {
        return version;
    }

    public void setVersion(Integer version) {
        this.version = version;
    }

    public Integer getId() {
        return id;
    }

    public void setId(Integer id) {
        this.id = id;
    }

    public String getProductId() {
        return productId;
    }

    public void setProductId(String productId) {
        this.productId = productId;
    }

    public String getImageUrl() {
        return imageUrl;
    }

    public void setImageUrl(String imageUrl) {
        this.imageUrl = imageUrl;
    }

    public BigDecimal getPrice() {
        return price;
    }

    public void setPrice(BigDecimal price) {
        this.price = price;
    }
}

Below is a JUnit test class to save and retrieve products.

If you are new to JUnit, I’d suggest checking out my JUnit series of posts.

ProductRepositoryTest.java

package guru.springframework.repositories;

import guru.springframework.configuration.RepositoryConfiguration;
import guru.springframework.domain.Product;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import java.math.BigDecimal;

import static org.junit.Assert.*;

@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(classes = {RepositoryConfiguration.class})
public class ProductRepositoryTest {

   private ProductRepository productRepository;

   @Autowired
   public void setProductRepository(ProductRepository productRepository) {
       this.productRepository = productRepository;
   }

   @Test
   public void testSaveProduct(){
       //setup product
       Product product = new Product();
       product.setDescription("Spring Framework Guru Shirt");
       product.setPrice(new BigDecimal("18.95"));
       product.setProductId("1234");

       //save product, verify has ID value after save
       assertNull(product.getId()); //null before save
       productRepository.save(product);
       assertNotNull(product.getId()); //not null after save
       //fetch from DB
       Product fetchedProduct = productRepository.findOne(product.getId());

       //should not be null
       assertNotNull(fetchedProduct);

       //should equal
       assertEquals(product.getId(), fetchedProduct.getId());
       assertEquals(product.getDescription(), fetchedProduct.getDescription());

       //update description and save
       fetchedProduct.setDescription("New Description");
       productRepository.save(fetchedProduct);

	//get from DB, should be updated
       Product fetchedUpdatedProduct = productRepository
                                          .findOne(fetchedProduct.getId());
       assertEquals(fetchedProduct.getDescription(),
                                    fetchedUpdatedProduct.getDescription());

       //verify count of products in DB
       long productCount = productRepository.count();
       assertEquals(productCount, 1);

       //get all products, list should only have one
       Iterable<Product> products = productRepository.findAll();

       int count = 0;

       for(Product p : products){
           count++;
       }

       assertEquals(count, 1);
   }
}

Activating Logging in Hibernate

To activate the logging of the executed SQL statements with Spring Boot, set the log level of the org.hibernate.SQL category to DEBUG.

If you wish to see the bind values, you can set the log level of org.hibernate.type.descriptor.sql to TRACE .

If you are new to logging frameworks, refer my series on Log4J2.

Here is the logging configuration in the application.properties.

application.properties

#show sql statement
logging.level.org.hibernate.SQL=debug

#show sql values
logging.level.org.hibernate.type.descriptor.sql=trace

Here is the log output showing the SQL statements generated by Hibernate.

 org.hibernate.SQL=debug

2018-02-04 22:34:46.861 DEBUG 1065 --- [           main] org.hibernate.SQL                        : 
select product0_.id as id1_0_0_, product0_.description as descript2_0_0_, product0_.image_url as image_ur3_0_0_, product0_.price as price4_0_0_, product0_.product_id as product_5_0_0_, product0_.version as version6_0_0_ from product product0_ where product0_.id=?

org.hibernate.type.descriptor.sql=trace

2018-02-04 22:34:46.861 DEBUG 1065 --- [           main] org.hibernate.SQL                        : 
select product0_.id as id1_0_0_, product0_.description as descript2_0_0_, product0_.image_url as image_ur3_0_0_, product0_.price as price4_0_0_, product0_.product_id as product_5_0_0_, product0_.version as version6_0_0_ from product product0_ where product0_.id=?
2018-02-04 22:34:46.862 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicBinder      : 
binding parameter [1] as [INTEGER] - [1]
2018-02-04 22:34:46.862 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : 
extracted value ([descript2_0_0_] : [VARCHAR]) - [New Description]
2018-02-04 22:34:46.863 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : 
extracted value ([image_ur3_0_0_] : [VARCHAR]) - [http://springframework.guru/wp-content/uploads/2015/04/spring_framework_guru_shirt-rf412049699c14ba5b68bb1c09182bfa2_8nax2_512.jpg]
2018-02-04 22:34:46.863 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([price4_0_0_] : [NUMERIC]) - [18.95]
2018-02-04 22:34:46.863 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([product_5_0_0_] : [VARCHAR]) - [1234]
2018-02-04 22:34:46.863 TRACE 1065 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([version6_0_0_] : [INTEGER]) - [1]

Activating Logging with Spring Data JPA

If you are using Spring Data JPA with Hibernate as the persistence provider, add the following two lines in application.properties.

spring.jpa.show-sql=true
spring.jpa.properties.hibernate.format_sql=true

Here is the log output.

 Hibernate: 
    select
        product0_.id as id1_0_0_,
        product0_.description as descript2_0_0_,
        product0_.image_url as image_ur3_0_0_,
        product0_.price as price4_0_0_,
        product0_.product_id as product_5_0_0_,
        product0_.version as version6_0_0_ 
    from
        product product0_ 
    where
        product0_.id=?

Conclusion

As you can see, its very easy to enable the logging of SQL statements with Spring Boot and Hibernate.

Being able to see what Hibernate is actually doing with the database is very important.

Often, when I’m working on a Spring Boot project, I will enable the SQL output just as a sanity check. I may believe everything is okay. But I have, in fact, found problems which I was unaware of by examining the SQL output.

About jt

    You May Also Like

    9 comments on “Hibernate Show SQL

    1. April 27, 2018 at 12:34 am

      This is perfect and very helpful post! Thank you John

      Reply
    2. April 27, 2018 at 2:19 am

      Hi John,
      I there a way to print in the log output also the values of the parameters?
      Is it possible that the “?” to be replaced with the actual valuse used by hibernate?

      Thanks

      Reply
    3. May 1, 2018 at 2:54 am

      Thank you much John for this post.

      Reply
    4. August 27, 2018 at 11:41 am

      same applies for “application.yml” ?

      Reply
    5. August 26, 2019 at 6:03 am

      Thanks. It helps me a lot 🙂

      Reply
    6. October 29, 2020 at 9:50 am

      I believe there is a typo. show-sql should be show_sql

      Reply
    7. November 25, 2020 at 7:44 am

      hi,

      I try to achieve the same in an existing project which uses Spring and hibernate, but it does not consider anything I add to application.properties or log4j.properties (I added lots of them found on the web). I did add the above settings on both of them, but they simply are ignored. The only thing that works is to set the “false” to true in one of the xml files loaded with Srping context. This one logs hibernate logs to the console regardless of conigurations in .properties files, which I found is correct.

      Thus I would be thankful if you can point me to what I am missing here. My goal is to configure log4j.properties (or application.properties) to be able to log hibernate messages into a file. File appender is configured correctly in log4j.properties and was tested working with different loggers.

      Thnk you!

      Reply
      • December 2, 2021 at 4:33 am

        Hi Can you help how you configured hibernate sql properties to get sql query and statics like execution of that query. Also how can i configure separate configurations as per environment like dev/Test/Sbx/Production.
        Thanks and Regards,
        Hareesh

        Reply
    8. February 3, 2023 at 1:30 pm

      Adding these lines was very important in debugging a program I did not write.
      Especially since I was not that experienced in spring. But did design the DB.
      I think I learned them in one of your classes.

      Reply

    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.