JPA使用log4jdbc输出sql日志

Posted 2020-11-29 二奎

前面两篇介绍了JPA使用logback，log4j2输出sql日志，虽然可以实现输出Sql，但sql主体和参数都是分开输出的，不方便调试，对开发不友好，我们还是喜欢直接把sql拿过来，直接就可以在plsql中运行，那就太爽了。

而log4jdbc就可以实现这个功能：

同样使用上节的项目：我们再改一下POM：

增加：

<dependency>
            <groupId>com.googlecode.log4jdbc</groupId>
            <artifactId>log4jdbc</artifactId>
            <version>1.2</version>
            <scope>runtime</scope>
        </dependency>

yml配置文件修改：

server:
  port: 8086
spring:
  jpa:
    properties:
      hibernate:
        format_sql: true
    #配置在日志中打印出执行的 SQL 语句信息。
    #show-sql: true
  datasource:
    driver-class-name: net.sf.log4jdbc.DriverSpy
    url: jdbc:log4jdbc:mysql://***:3306/bmitest2?serverTimezone=Asia/Shanghai&useSSL=false&rewriteBatchedStatements=true&useCursorFetch=true
    username: root
    password: ***

logging:
  level:
    root: info

注意蓝色部分的修改。

2020-05-08 15:15:07.284 [main] INFO  jdbc.audit - 1. Connection.isValid(5) returned true
2020-05-08 15:15:07.285 [main] INFO  jdbc.audit - 1. Connection.getAutoCommit() returned true
2020-05-08 15:15:07.285 [main] INFO  jdbc.audit - 1. Connection.setAutoCommit(false) returned 
2020-05-08 15:15:07.336 [main] INFO  jdbc.audit - 1. PreparedStatement.new PreparedStatement returned 
2020-05-08 15:15:07.337 [main] INFO  jdbc.audit - 1. Connection.prepareStatement(select opnfiledo0_.id as id1_0_0_ from opn_file opnfiledo0_ where opnfiledo0_.id=?) returned net.sf.log4jdbc.PreparedStatementSpy@39acd1f1
2020-05-08 15:15:07.340 [main] INFO  jdbc.audit - 1. PreparedStatement.setString(1, "14247") returned 
2020-05-08 15:15:07.342 [main] INFO  jdbc.sqlonly - select opnfiledo0_.id as id1_0_0_ from opn_file opnfiledo0_ where opnfiledo0_.id=‘14247‘ 

2020-05-08 15:15:07.347 [main] INFO  jdbc.sqltiming - select opnfiledo0_.id as id1_0_0_ from opn_file opnfiledo0_ where opnfiledo0_.id=‘14247‘ 
 {executed in 4 msec}
2020-05-08 15:15:07.352 [main] INFO  jdbc.resultset - 1. ResultSet.new ResultSet returned 
2020-05-08 15:15:07.353 [main] INFO  jdbc.audit - 1. PreparedStatement.executeQuery() returned net.sf.log4jdbc.ResultSetSpy@27e21083
2020-05-08 15:15:07.355 [main] INFO  jdbc.resultset - 1. ResultSet.next() returned true
2020-05-08 15:15:07.361 [main] INFO  jdbc.resultset - 1. ResultSet.next() returned false
2020-05-08 15:15:07.364 [main] INFO  jdbc.resultset - 1. ResultSet.close() returned 
2020-05-08 15:15:07.365 [main] INFO  jdbc.audit - 1. PreparedStatement.getMaxRows() returned 0
2020-05-08 15:15:07.365 [main] INFO  jdbc.audit - 1. PreparedStatement.getQueryTimeout() returned 0
2020-05-08 15:15:07.365 [main] INFO  jdbc.audit - 1. PreparedStatement.close() returned 
2020-05-08 15:15:07.373 [main] INFO  jdbc.audit - 1. Connection.commit() returned 
2020-05-08 15:15:07.374 [main] INFO  jdbc.audit - 1. Connection.setAutoCommit(true) returned 
2020-05-08 15:15:07.385 [main] INFO  jdbc.audit - 1. Connection.clearWarnings() returned 
2020-05-08 15:15:07.386 [main] INFO  jdbc.audit - 1. Connection.clearWarnings() returned 

修改后，我们可以看到sql了，但是多了很多我们不需要的日志，可以通过修改日志配置文件去掉，我们以log4j2为例：

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
    <Appenders>

        <!--这个输出控制台的配置-->
        <console name="Console" target="SYSTEM_OUT">
            <!--输出日志的格式-->
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t{2}] %-5level %logger{4} - %msg%n"/>
        </console>
        <!-- 这个会打印出所有的info及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="RollingFileInfo" fileName="logs/cis-mr-audit.log"
                     filePattern="logs/$${date:yyyy-MM}/cis-mr-audit-%d{yyyy-MM-dd}-%i.log">
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%p] - %l - %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="5 MB"/>
            </Policies>
        </RollingFile>

    </Appenders>
    <Loggers>
        <logger name="jdbc.audit" level="OFF"/>
        <logger name="jdbc.resultset" level="OFF"/>
        <logger name="jdbc.connection" level="OFF"/>
        <logger name="jdbc.sqltiming" level="OFF"/>
        <Root level="info">
            <AppenderRef ref="Console" />
            <AppenderRef ref="RollingFileInfo" />
        </Root>
    </Loggers>
</Configuration>

2020-05-08 15:20:55.334 [main] INFO  apache.coyote.http11.Http11NioProtocol - Starting ProtocolHandler ["http-nio-auto-1"]
2020-05-08 15:20:55.357 [main] INFO  web.embedded.tomcat.TomcatWebServer - Tomcat started on port(s): 61870 (http) with context path ‘‘
2020-05-08 15:20:55.358 [main] INFO  com.example.demo.FileControllerTest - Started FileControllerTest in 4.543 seconds (JVM running for 7.048)
2020-05-08 15:20:55.413 [main] INFO  ContainerBase.[Tomcat].[localhost].[/] - Initializing Spring TestDispatcherServlet ‘‘
2020-05-08 15:20:55.413 [main] INFO  test.web.servlet.TestDispatcherServlet - Initializing Servlet ‘‘
2020-05-08 15:20:55.428 [main] INFO  test.web.servlet.TestDispatcherServlet - Completed initialization in 14 ms
2020-05-08 15:20:55.548 [main] INFO  jdbc.sqlonly - select opnfiledo0_.id as id1_0_0_ from opn_file opnfiledo0_ where opnfiledo0_.id=‘14247‘ 

日志输出就正常了。

调整一下日志级别为error:

logging:
  level:
    root: error

没事sql日志输出。

这个方法更为简单实用。推荐使用。