Spring Boot下基于JPA抓取SQL运行时的参数值

原创 2016年08月31日 13:19:44

引言: 在系统开发过程中,涉及到数据库操作都是SQL的天下,基于ORM的各类框架来简化开发;在JPA/Hibernate方案中,只提供了SQL的打印输出,但并未输入SQL的参数值是多少,这里将解决这个问题,告知具体如何来实现这个操作。

1.  技术栈的介绍

   JDK 1.8,  Spring Boot 1.4.0, Mysql 5.7,  默认Tomcat JDBC Connection Pool.

2.  依赖包

    Spring Boot中的JPA依赖包:

 <dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-data-jpa</artifactId>
		</dependency>
  Mysql的驱动程序:

 <dependency>
			<groupId>mysql</groupId>
			<artifactId>mysql-connector-java</artifactId>
			<scope>runtime</scope>
		</dependency>
  log4jdbc的依赖包:

     <dependency>
			<groupId>com.googlecode.log4jdbc</groupId>
			<artifactId>log4jdbc</artifactId>
			<version>1.2</version>
		</dependency>
3. log4jdbc的介绍

    log4jdbc使用SLF4J(Simple Logging Facade For Java)作为日志系统。特性:

  •    支持JDBC3和JDBC4,其中JDBC3对应于JDK 1.4 or 1.5,JDBC4要求JDK 1.6或以上。
  •    支持现有大部分JDBC驱动。
  •   易于配置(在大部分情况下,只需要改变驱动类名并在jdbc url前加上”jdbc:log4“,设置好日志输出级别)。
  •    能够自动把SQL变量值加到SQL输出日志中,改进易读性和方便调试。
  •    能够快速标识出应用程序中执行比较慢的SQL语句。
  •    能够生成SQL连接数信息帮助识别连接池/线程问题。

   综合一句话,log4jdbc可以帮我们实现一个抓取SQL中实际使用值的功能。

   项目地址【需要翻墙,翻墙问题自行解决】: https://code.google.com/p/log4jdbc/

4.  Spring Boot示例

     application.properties内容:   

spring.datasource.url = jdbc:log4jdbc:mysql://localhost:3306/mealsystem?useUnicode=true&characterEncoding=utf-8
spring.datasource.username = root
spring.datasource.password = 123456
spring.datasource.driverClassName = net.sf.log4jdbc.DriverSpy
这里需要注意的是mysql的原来的驱动程序Class Name:

#spring.datasource.driverClassName = com.mysql.jdbc.Driver 
将被  net.sf.log4jdbc.DriverSpy来替代,可以理解为DriverSpy做为mysql驱动的代理来捕捉SQL的信息。

数据库连接的URL需要进行修改为:

   原来的: jdbc:mysql://localhost:3306/mealsystem

   现在的:  jdbc:log4jdbc:mysql://localhost:3306/mealsystem

  初次之外,无需额外的变化需求,其余代码都一致即可获得运行中的SQL信息。

5.  SQL捕捉示例

2016-08-30 20:38:37.362  INFO 13288 --- [           main] com.rain.wx.meal.dao.TestEntityTest      : Started TestEntityTest in 19.879 seconds (JVM running for 21.522)
2016-08-30 20:38:37.432  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.isClosed() returned false
2016-08-30 20:38:37.436  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned true
2016-08-30 20:38:37.457  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.setAutoCommit(false) returned 
Hibernate: insert into test (created_time, updated_time, version, name) values (?, ?, ?, ?)
2016-08-30 20:38:37.495  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getCatalog() returned mealsystem
2016-08-30 20:38:37.535  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.new PreparedStatement returned 
2016-08-30 20:38:37.541  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.prepareStatement(insert into test (created_time, updated_time, version, name) values (?, ?, ?, ?), 1) returned net.sf.log4jdbc.PreparedStatementSpy@3e0704e2
2016-08-30 20:38:37.549  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getMaxFieldSize() returned 4194304
2016-08-30 20:38:37.550  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getMaxRows() returned 0
2016-08-30 20:38:37.550  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getQueryTimeout() returned 0
2016-08-30 20:38:37.551  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getFetchDirection() returned 1000
2016-08-30 20:38:37.551  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getFetchSize() returned 0
2016-08-30 20:38:37.554  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.setNull(1, 93) returned 
2016-08-30 20:38:37.554  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.setNull(2, 93) returned 
2016-08-30 20:38:37.556  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.setInt(3, 0) returned 
2016-08-30 20:38:37.557  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.setString(4, "我的天空") returned 
2016-08-30 20:38:37.560  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned false
2016-08-30 20:38:37.561  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned false
2016-08-30 20:38:37.561  INFO 13288 --- [           main] jdbc.sqlonly                             : insert into test (created_time, updated_time, version, name) values (NULL, NULL, 0, '我的天空') 

2016-08-30 20:38:37.585  INFO 13288 --- [           main] jdbc.sqltiming                           : insert into test (created_time, updated_time, version, name) values (NULL, NULL, 0, '我的天空') 
 {executed in 24 msec}
2016-08-30 20:38:37.585  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.executeUpdate() returned 1
2016-08-30 20:38:37.586  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.new ResultSet returned 
2016-08-30 20:38:37.586  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getGeneratedKeys() returned net.sf.log4jdbc.ResultSetSpy@40277077
2016-08-30 20:38:37.586  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.getMetaData() returned com.mysql.jdbc.ResultSetMetaData@4cb773c5 - Field level information: 
	com.mysql.jdbc.Field@2c4eae94[catalog=null,tableName=,originalTableName=null,columnName=GENERATED_KEY,originalColumnName=null,mysqlType=-1( Unknown MySQL Type # -1),flags=, charsetIndex=0, charsetName=UTF-8]
2016-08-30 20:38:37.591  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.next() returned true
2016-08-30 20:38:37.593  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.getMetaData() returned com.mysql.jdbc.ResultSetMetaData@4c114687 - Field level information: 
	com.mysql.jdbc.Field@2c4eae94[catalog=null,tableName=,originalTableName=null,columnName=GENERATED_KEY,originalColumnName=null,mysqlType=-1( Unknown MySQL Type # -1),flags=, charsetIndex=0, charsetName=UTF-8]
2016-08-30 20:38:37.598  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.getLong(1) returned 6
2016-08-30 20:38:37.598  INFO 13288 --- [           main] jdbc.resultset                           : 4. ResultSet.close() returned 
2016-08-30 20:38:37.599  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getMaxRows() returned 0
2016-08-30 20:38:37.599  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getQueryTimeout() returned 0
2016-08-30 20:38:37.599  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.isClosed() returned false
2016-08-30 20:38:37.599  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.clearParameters() returned 
2016-08-30 20:38:37.648  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.commit() returned 
2016-08-30 20:38:37.674  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.setAutoCommit(true) returned 
2016-08-30 20:38:37.675  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.isClosed() returned false
2016-08-30 20:38:37.676  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getWarnings() returned null
2016-08-30 20:38:37.676  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.clearWarnings() returned 
2016-08-30 20:38:37.676  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.clearWarnings() returned 
2016-08-30 20:38:37.681  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.isClosed() returned false
2016-08-30 20:38:37.706  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.setReadOnly(true) returned 
2016-08-30 20:38:37.706  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned true
2016-08-30 20:38:37.744  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.setAutoCommit(false) returned 
Hibernate: select testentity0_.id as id1_5_0_, testentity0_.created_time as created_2_5_0_, testentity0_.updated_time as updated_3_5_0_, testentity0_.version as version4_5_0_, testentity0_.name as name5_5_0_ from test testentity0_ where testentity0_.id=?
2016-08-30 20:38:37.751  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getCatalog() returned mealsystem
2016-08-30 20:38:37.793  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.new PreparedStatement returned 
2016-08-30 20:38:37.793  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.prepareStatement(select testentity0_.id as id1_5_0_, testentity0_.created_time as created_2_5_0_, testentity0_.updated_time as updated_3_5_0_, testentity0_.version as version4_5_0_, testentity0_.name as name5_5_0_ from test testentity0_ where testentity0_.id=?) returned net.sf.log4jdbc.PreparedStatementSpy@5b32e0b1
2016-08-30 20:38:37.793  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getMaxFieldSize() returned 4194304
2016-08-30 20:38:37.794  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getMaxRows() returned 0
2016-08-30 20:38:37.794  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getQueryTimeout() returned 0
2016-08-30 20:38:37.794  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getFetchDirection() returned 1000
2016-08-30 20:38:37.794  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.getFetchSize() returned 0
2016-08-30 20:38:37.796  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.setLong(1, 6) returned 
2016-08-30 20:38:37.797  INFO 13288 --- [           main] jdbc.audit                               : 4. PreparedStatement.isWrapperFor(java.sql.CallableStatement) returned false
2016-08-30 20:38:37.798  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned false
2016-08-30 20:38:37.798  INFO 13288 --- [           main] jdbc.audit                               : 4. Connection.getAutoCommit() returned false
2016-08-30 20:38:37.798  INFO 13288 --- [           main] jdbc.sqlonly                             : select testentity0_.id as id1_5_0_, testentity0_.created_time as created_2_5_0_, testentity0_.updated_time 
as updated_3_5_0_, testentity0_.version as version4_5_0_, testentity0_.name as name5_5_0_ from 
test testentity0_ where testentity0_.id=6 

2016-08-30 20:38:37.833  INFO 13288 --- [           main] jdbc.sqltiming                           : select testentity0_.id as id1_5_0_, testentity0_.created_time as created_2_5_0_, testentity0_.updated_time 
as updated_3_5_0_, testentity0_.version as version4_5_0_, testentity0_.name as name5_5_0_ from 
test testentity0_ where testentity0_.id=6 
 {executed in 35 msec}
  大家可以分析其中的Log内容,可以发现,Hibernate的SQL输出是没有具体的参数值的:
    Hibernate: insert into test (created_time, updated_time, version, name) values (?, ?, ?, ?)

   log4jdbc中的日志输出如下:

2016-08-30 20:38:37.561  INFO 13288 --- [           main] jdbc.sqlonly                             : insert into test (created_time, updated_time, version, name) values (NULL, NULL, 0, '我的天空') 

2016-08-30 20:38:37.585  INFO 13288 --- [           main] jdbc.sqltiming                           : insert into test (created_time, updated_time, version, name) values (NULL, NULL, 0, '我的天空') 
 {executed in 24 msec}
  可以发现其Insert语句是有具体的值存在的,额外还有执行所使用的时间。

6. 参考资料

  •   http://www.cnblogs.com/xdp-gacl/p/4081848.html
  •  http://my.oschina.net/kzhou/blog/149532


spring data jpa 执行sql

Update.class,用于创建数据库表import org.springframework.data.jpa.repository.*; import org.springframework.st...
  • wyljz
  • wyljz
  • 2016年09月23日 16:02
  • 4825

利用log4j显示hibernate打印sql中的参数

利用log4j显示hibernate打印sql中的参数 大家都知道在 hibernate.cfg.xml 配置文件中添加以下三条配置,就可以在控制台显示执行的sql: true ...

使用spring-boot-starter-data-jpa 怎么配置使运行时输出SQL语句

在 application.properties 中加入以下配置spring.jpa.show-sql=true

springmvc+jpa+hibernate 日志打印

jar包添加 com.googlecode.log4jdbc log4jdbc 1.2 打...
  • wm5920
  • wm5920
  • 2017年08月02日 08:15
  • 504

Spring Boot + Jpa(Hibernate) 架构基本配置

1、基于springboot-1.4.0.RELEASE版本测试 2、springBoot + Hibernate + Druid + Mysql + servlet(jsp) 不废话,直接...

Spring Data JPA初使用

我们都知道Spring是一个非常优秀的JavaEE整合框架,它尽可能的减少我们开发的工作量和难度。   在持久层的业务逻辑方面,Spring开源组织又给我们带来了同样优秀的Spring Data...

Spring Boot JPA 连接数据库

本文将介绍如何在Spring Boot 工程中添加JPA作为持久化方式。修改 pom.xml 依赖与上一篇介绍的 jdbc 不同的是 spring-boot-starter-jdbc 修改为 spri...
  • catoop
  • catoop
  • 2016年01月13日 09:41
  • 30111

使用JPA来执行本地SQL语句查询

@PersistenceContext private EntityManager manager; String sql = "select max(wm.id) as maxId, m...

JPA的查询语言—使用原生SQL

ntityManager API 提供了创建 Query 实例以执行原生 SQL 语句的createNativeQuery方法。   实体User: [java] view plain...

spring boot控制台打印sql日志 logging logback

spring boot已经集成logback日志 只需要在application.properties做如下配置即可 #####################################...
  • zlxls
  • zlxls
  • 2017年09月14日 11:22
  • 1168
内容举报
返回顶部
收藏助手
不良信息举报
您举报文章:Spring Boot下基于JPA抓取SQL运行时的参数值
举报原因:
原因补充:

(最多只允许输入30个字)