Introduction

In this article, I’m going to show you the best way to log SQL statements when using Spring Boot.

Logging SQL queries is very important, as it allows you to validate the number of generated statements, the syntax of the auto-generated queries, as well as prove that JDBC batching works as expected.

Don’t log SQL statements with the Spring Boot show-sql property

It’s very common for a Spring Boot application to store data in a relational database, and, most often, Spring Data JPA is the default data access technology.

While Spring Data JPA is generic and can work with any JPA provider, in reality, the vast majority of projects using Spring Data JPA happen to use Hibernate as well since Hibernate is the default JPA provider used by Spring Boot.

image

To log SQL statements generated by Spring Data JPA, Spring Boot provides the spring.jpa.show-sql property that you can add to your application.properties configuration file:

1
spring.jpa.show-sql=true

However, this is not a good idea because, behind the scenes, it simply enables the Hibernate hibernate.show_sql configuration property:

1
jpaProperties.put("hibernate.show_sql", "true");

As I explained in this article, you should not use the hibernate.show_sql configuration property as it’s basically the equivalent of printing your SQL queries using System.out.println .

For the same reasons we are using logging frameworks and not System.out.println calls for application logging, we should not use the show_sql properties provided by Spring Boot or Hibernate.

Hibernate logging limitations

A slightly better option is to enable SQL logging at Hibernate-level by providing the following logger options in your application.properties configuration file:

1
2
logging.level.org.hibernate.SQL=debug
logging.level.org.hibernate.type.descriptor.sql=trace

And, Spring Boot will log SQL statements like this:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
org.hibernate.SQL :
    SELECT
       u.id AS id1_7_,
       u.email AS email5_7_,
       u.external_id AS external6_7_,
       u.first_name AS first_na7_7_,
       u.last_name AS last_nam9_7_,
    FROM users u
    WHERE u.email = ?
     
o.h.t.d.sql.BasicBinder :
    binding parameter [1] as [VARCHAR] - [john.doe@acme.com]

The org.hibernate.SQL log message is printed when the JDBC PreparedStatement is created, while the parameter binding log messages are printed when the setParameter query methods are executed.

This Hibernate-based SQL logging option also has several drawbacks:

  • for batching, it will not be clear how many statements are actually sent to the database server since the log message is printed during the prepare phase and not at the moment the executeBatch method is called.
  • the org.hibernate.type.descriptor.sql logger only works for the built-in Hibernate Core Types. If you’re using the Hibernate Types project, then the Hibernate package logger setting will not work for non-standard Hibernate Types.

DataSource-Proxy

As I explained in this article, DataSource-Proxy is one of the best ways to log SQL statements.

Since it proxies the JDBC DataSource , it can log statements for any data access layer technology you might be using with Spring Boot. Even if you mix JPA and jOOQ, DataSource-Proxy will print all your SQL statements that are executed via the JDBC Connection that was proxied.

Another great advantage of DataSource-Proxy is that you can assert the number statements that are generated by the data access layer. Check out this article for a step-by-step tutorial.

When Spring Boot starts, it creates a DataSource to be used by JPA, Hibernate, or other data access technologies. In order to use DataSource-Proxy, we need to proxy the default JDBC DataSource and allow the application to use the Proxy instead.

Luckily, Arthur Gavlyukovskiy saved the day and provided us with a list of Spring Boot DataSource starters that support DataSource-Proxy, FlexyPool, or P6spy.

All you need to do is add the following Maven dependency:

1
2
3
4
5
<dependency>
    <groupId>com.github.gavlyukovskiy</groupId>
    <artifactId>datasource-proxy-spring-boot-starter</artifactId>
    <version>${ds-proxy-spring-boot-starter.version}</version>
</dependency>

And now Spring Boot can print meaningful SQL statements that were generated by any data access technology:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
Name:dataSource, Connection:5, Time:1, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["
    SELECT
       u.id AS id1_7_,
       u.email AS email5_7_,
       u.external_id AS external6_7_,
       u.first_name AS first_na7_7_,
       u.last_name AS last_nam9_7_,
    FROM users u
    WHERE u.email = ?
"]
Params:[(
    john.doe@acme.com
)]

Cool, right?

Conclusion

If you’re using Spring Boot with a relational database, then you should definitely have a good way to log SQL statements.

While you might think that the default show-sql property or the Hibernate logging option is sufficient, they are not worth it. Using DataSource-Proxy is just as easy and, not only it provides better logging options, but you can use it to detect N+1 query issues automatically.

Reference https://vladmihalcea.com/log-sql-spring-boot/