JPA 使用logback输出SQL日志到文件

通常的logback配置文件是这样：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
    <!--输出到控制台-->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <!--输出到文件-->
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logback.%d{yyyy-MM-dd}.log</fileNamePattern>
        </rollingPolicy>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="console" />
        <appender-ref ref="file" />
    </root>

</configuration>

我们使用的是spring boot自带的logback所以pom文件不用做调整，只需要加上JPA相关代码即可。

controller的代码只是做一个简单的查询带参数：

@Transactional
public class FileController {

    @Autowired
    private FileRepository fileRepository;

    @RequestMapping("getfile")
    public String getOpinionBills() {
        OpnFileDO one = fileRepository.getOne("14247");
        return one.toString();
    }


}

对它进行单元测试：

public class FileControllerTest extends ControllerTestBase {
    @Test
    public void fileTest() throws Exception {
        mockMvc
                .perform(MockMvcRequestBuilders.get("/getfile") // 测试的相对地址
                        .accept(MediaType.APPLICATION_JSON_UTF8) // accept response content type
                )
                .andExpect(status().isOk()) // 期待返回状态吗码200
                .andDo(MockMvcResultHandlers.print()); // 打印返回的 http response 信息
    }
}

测试代码也不重要，只是就是为了方便测试，运行测试：

这时的输出日志中是没有日志的。文件中也是没有的：

下面加sql日志，最简单的方法就是修改yml配置文件：

spring:
  jpa:
    properties:
      hibernate:
        format_sql: true
    #配置在日志中打印出执行的 SQL 语句信息。
    show-sql: true

这样就可以console中看到格式化后的sql,但这里没有参数。

接下来，我们要在console中看到参数，并在日志文件中看到Sql和参数，修改logback配置文件：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
    <!--输出到控制台-->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <!--输出到文件-->
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logback.%d{yyyy-MM-dd}.log</fileNamePattern>
        </rollingPolicy>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
    
    <!-- 1. 输出SQL 到控制台和文件-->
    <logger name="org.hibernate.SQL" additivity="false" >
        <level value="DEBUG" />
        <appender-ref ref="file" />
        <appender-ref ref="console" />
    </logger>
<!--    &lt;!&ndash; 2. 输出SQL 的参数到控制台和文件&ndash;&gt;-->
    <logger name="org.hibernate.type.descriptor.sql.BasicBinder" additivity="false" level="TRACE" >
        <level value="TRACE" />
        <appender-ref ref="file" />
        <appender-ref ref="console" />
    </logger>

    <root level="info">
        <appender-ref ref="console" />
        <appender-ref ref="file" />
    </root>

</configuration>

运行测试后发现：

14:06:54.130 [main] DEBUG org.hibernate.SQL - 
    select
        opnfiledo0_.id as id1_0_0_
    from
        file opnfiledo0_ 
    where
        opnfiledo0_.id=?
Hibernate: 
    select
        opnfiledo0_.id as id1_0_0_
    from
        file opnfiledo0_ 
    where
        opnfiledo0_.id=?
14:06:54.149 [main] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [VARCHAR] - [14247]

参数已经有了，但是Sql多打了一遍。

日志文件中则正常

14:06:54.130 [main] DEBUG org.hibernate.SQL - 
    select
        opnfiledo0_.id as id1_0_0_
    from
        file opnfiledo0_ 
    where
        opnfiledo0_.id=?
14:06:54.149 [main] TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [VARCHAR] - [14247]

我们把yml中的：show-sql: true

现在console中的日志和日志文件中的sql都正常了。

开发环境这样的配置没有问题，上生产后，我们的日志级别error怎么办：

不能修改logback的配置文件，只能修改yml配置文件：

logging:
  level:
    root: error

 发现这个Sql还是存在，不满足需求。

我们回退到原始的logback配置文件那里，不修改logback的配置文件，而是修改yml文件中日志的配置来实现打印sql:

logging:
  level:
    root: info
    org:
      hibernate:
        SQL: debug
        type:
          descriptor:
            sql:
              BasicBinder: trace

没有问题，我们在调整yml实现生产环境的日志级别：

logging:
  level:
    root: error
    org:
      hibernate:
        SQL: error
        type:
          descriptor:
            sql:
              BasicBinder: error

当然还有一种解决方法，就是再写一个logback的配置文件，通过修改yml配置文件的logging.config来指定配置文件来实现修改日志级别的功能，只不过这种方式显的有点麻烦了。