Spring Boot下如何记录SQL语句、SQL参数、慢SQL日志

在我们程序在访问数据库，出现bug或者性能问题的时候，我们希望把SQL语句以及参数都打印出来，以便于我们定位bug和性能问题。

你可能会使用的方式

通常情况下，以使用Spring Data JPA和Hibernate为例（别走开，方案是和数据库访问技术无关的，理论上Mybatis，JDBC都可以使用），我们在application.yaml 里配置使用：

spring.jpa.show-sql: true

但这样的设置只能在开发测试环境里设置，因为使用此属性等同于使用System.out.println打印SQL语句，这将会有性能的问题。而且也不能显示SQL的参数。

或者我们通过设置Hibernate属性在application.yaml配置：

logging.level.org.hibernate.SQL: debug
logging.level.org.hibernate.type.descriptor.sql: trace

这个方案比上面的方案好一些，但是也有几个问题：

在批处理情况，不清楚有多少语句实际发送到数据库服务器，因为日志消息是在准备阶段打印的，而不是在调用executeBatch方法时打印的。
org.hibernate.type.descriptor.sql只能记录内置的Hibernate核心类型，如果你使用自定义的类型，将不会被打印。

现在我们介绍一个开源项目，叫做：datasource-proxy，地址： https://github.com/jdbc-observations/datasource-proxy 。

它提供了一个JDBC的DataSource 的代理：ProxyDataSource ，这就意味着它可以用在任何在Spring Boot下的数据访问技术，如：JPA、Mybatis等。就算混合使用多种数据访问技术，datasource-proxy也能打印所有的通过JDBC连接的语句。

使用datasource-proxy

新建演示项目

添加相关依赖我们可以直接添加datasource-proxy的依赖，然后自己通过ProxyDataSourceBuilder 来创建ProxyDataSource。不过我们并不需要这样做，因为已经有人给我们写好了datasource-proxy的Spring Boot Starter，我们直接使用这个starter就可以直接自动配置好datasource-proxy。starter的地址： https://github.com/gavlyukovskiy/spring-boot-data-source-decorator 。

Gradle

implementation 'com.github.gavlyukovskiy:datasource-proxy-spring-boot-starter:1.8.1'

或Maven

<dependency>
    <groupId>com.github.gavlyukovskiy</groupId>
    <artifactId>datasource-proxy-spring-boot-starter</artifactId>
    <version>1.8.1</version>
</dependency>

简单的数据访问演示类

@Data
@Entity
@AllArgsConstructor
@NoArgsConstructor
public class Person {

    @Id
    @GeneratedValue(strategy = GenerationType.IDENTITY)
    private Long id;
    private String name;
    private Integer age;
}
public interface PersonRepository extends JpaRepository <Person, Long> {
    List<Person> findByNameStartsWith(String name);
}

简单的数据访问查询测试

@SpringBootApplication
public class LoggingSqlApplication {

   public static void main(String[] args) {
      SpringApplication.run(LoggingSqlApplication.class, args);
   }

   @Bean
   CommandLineRunner commandLineRunner(PersonRepository personRepository){
      return args -> {
         personRepository.save(new Person(null,"wiselyman001", 18));
         personRepository.save(new Person(null,"wiselyman002", 18));
         personRepository.save(new Person(null,"wiselyman003", 18));
         personRepository.save(new Person(null,"wiselyman004", 18));
         personRepository.findByNameStartsWith("wiselyman");
      };
   }
}

datasource-proxy的核心配置

datasource-proxy-spring-boot-starter 为我们提供了一个DataSourceProxyProperties来配置DataSourceProxy ，我们可以通过application.yaml 来配置。如：

# 设置日志库，默认为slf4j(slf4j, jul, common, sysout)
decorator.datasource.datasource-proxy.logging: slf4j

# 开启所有的查询到日志，默认为true
decorator.datasource.datasource-proxy.query.enable-logging: true
decorator.datasource.datasource-proxy.query.log-level: debug
# 日志名称设置
decorator.datasource.datasource-proxy.query.logger-name:

# 设置慢SQL的情况，慢SQL的日志级别是WARN
decorator.datasource.datasource-proxy.slow-query.enable-logging: true
decorator.datasource.datasource-proxy.slow-query.log-level: warn
decorator.datasource.datasource-proxy.slow-query.logger-name:
# 设置被认为是慢sql的时间并用日志记录下来
decorator.datasource.datasource-proxy.slow-query.threshold: 300

decorator.datasource.datasource-proxy.multiline: true
decorator.datasource.datasource-proxy.json-format: false
# 开启查询指标
decorator.datasource.datasource-proxy.count-query: false

上面是默认配置，若满足要求无需单独进行设置。

如我们没有特殊的定制，我们只需在application.yaml加上即可使用：

logging.level.net.ttddyy.dsproxy.listener: debug

运行程序

Name:dataSource, Connection:3, Time:36, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["insert into person (age, name) values (?, ?)"]
Params:[(18,wiselyman001)]
2022-10-17 17:13:16.907 DEBUG 12740 --- [           main] n.t.d.l.l.SLF4JQueryLoggingListener      : 
Name:dataSource, Connection:4, Time:34, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["insert into person (age, name) values (?, ?)"]
Params:[(18,wiselyman002)]
2022-10-17 17:13:17.041 DEBUG 12740 --- [           main] n.t.d.l.l.SLF4JQueryLoggingListener      : 
Name:dataSource, Connection:5, Time:33, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["insert into person (age, name) values (?, ?)"]
Params:[(18,wiselyman003)]
2022-10-17 17:13:17.183 DEBUG 12740 --- [           main] n.t.d.l.l.SLF4JQueryLoggingListener      : 
Name:dataSource, Connection:6, Time:36, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["insert into person (age, name) values (?, ?)"]
Params:[(18,wiselyman004)]
2022-10-17 17:13:17.407 DEBUG 12740 --- [           main] n.t.d.l.l.SLF4JQueryLoggingListener      : 
Name:dataSource, Connection:7, Time:37, Success:True
Type:Prepared, Batch:False, QuerySize:1, BatchSize:0
Query:["select person0_.id as id1_0_, person0_.age as age2_0_, person0_.name as name3_0_ from person person0_ where person0_.name like ? escape ?"]
Params:[(wiselyman%,\)]