Java - log4jdbc 使用与原理介绍（SQL/日志监控）

Java - log4jdbc（SQL/日志监控）

前言

之前老板让实现一个日志服务器，然而我们都不知道已经有现成的日志监控包直接使用（没有站在巨人肩膀上干活，害）

本篇主要介绍 log4jdbc，在进行系统开发时，我们一般会查看执行的SQL/了解SQL执行时间，这个时候其实可以代码在sql执行前后计算时间，框架执行sql的时候进行sql输出，其实也是可以实现的，但是有更简单的干嘛不用呢~，学习了 log4jdbc 然后来记录一下

log4jdbc介绍

1、简介

log4jdbc 是一个 Java JDBC Driver，可以记录 SQL 日志和 SQL 执行时间等信息，使用 SLF4J作为日志系统

日志系统相关内容：（一个日志门面 一个日志实现 构成日志系统）

2、特性

• 同时支持 JDBC3 和 JDBC4
• 配置简单
• 可将 SQL 中的 ？更换成实际的参数
• 能够 显示 SQL 的 执行时间
• 显示 SQL Connection 数量
• 可以与JDK1.4+和SLF4J1.X等大多数常见的JDBC驱动协同工作
• 开放源码

3、驱动支持

log4jdbc 可以会加载以下驱动:

源码可看：net.sf.log4jdbc.sql.jdbcapi

Driver Class	Database Type
oracle.jdbc.driver.OracleDriver	Older Oracle Driver
oracle.jdbc.OracleDriver	Newer Oracle Driver
com.sybase.jdbc2.jdbc.SybDriver	Sybase
net.sourceforge.jtds.jdbc.Driver	jTDS SQL Server & Sybase driver
com.microsoft.jdbc.sqlserver.SQLServerDriver	Microsoft SQL Server 2000 driver
com.microsoft.sqlserver.jdbc.SQLServerDriver	Microsoft SQL Server 2005 driver
weblogic.jdbc.sqlserver.SQLServerDriver	Weblogic SQL Server driver
com.informix.jdbc.IfxDriver	Informix
org.apache.derby.jdbc.ClientDriver	Apache Derby client/server driver, aka the Java DB
org.apache.derby.jdbc.EmbeddedDriver	Apache Derby embedded driver, aka the Java DB
com.mysql.jdbc.Driver	MySQL
org.postgresql.Driver	PostgresSQL
org.hsqldb.jdbcDriver	HSQLDB pure Java database
org.h2.Driver	H2 pure Java database

4、logger 介绍

log4jdbc 中使用了以下 7 种logger，可以进行相应的配置来实现需求

logger	描述
jdbc.sqlonly	仅仅记录 SQL 语句，会将占位符？替换为实际的参数
jdbc.sqltiming	记录 SQL 语句实际的执行时间
jdbc.audit	除了 ResultSet 之外的所有JDBC调用信息，篇幅较长
jdbc.resultset	包含 ResultSet 的信息，输出篇幅较长
jdbc.connection	输出了 Connection 的 open、close 等信息
log4jdbc.debug	内部调试使用，输出 log4jdbc spy 加载驱动时的信息
jdbc.resultsettable	显示前滚结果集的记录器

一般常用的是这5个：jdbc.audit jdbc.resultset jdbc.sqlonly jdbc.sqltiming jdbc.connection

log4jdbc 使用

以下 基于 SpringBoot 框架的项目进行使用介绍

1、导包

使用首先导包

<dependency>
      <groupId>org.bgee.log4jdbc-log4j2</groupId>
      <artifactId>log4jdbc-log4j2-jdbc4.1</artifactId>
      <version>1.16</version>
</dependency>

2、简单使用

2.1 配置

在使用 log4jdbc 时，需要进行三个配置：

• 更改数据库连接信息
• 编写 log4jdbc.log4j2.properties 文件
• 配置 logger

（1）更改数据库连接信息

主要修改 driverClassName 与 url，以yaml 配置为例：

• url 加上前缀 jdbc:log4
• driverClassName 改为 net.sf.log4jdbc.sql.jdbcapi.DriverSpy

# 修改前
driverClassName: com.mysql.jdbc.Driver
url: mysql://localhost:3306/springboot?useUnicode=true&characterEncoding=UTF-8

# 修改后
driverClassName: net.sf.log4jdbc.sql.jdbcapi.DriverSpy
url: jdbc:log4jdbc:mysql://localhost:3306/springboot?useUnicode=true&characterEncoding=UTF-8

（2）编写 log4jdbc.log4j2.properties 文件

在 resources 目录下新建 log4jdbc.log4j2.properties 文件，可配置信息如下：

默认文件名称为log4jdbc.log4j2.properties ，如果想自定义配置，需要在System properties文件中指定 log4jdbc.log4j2.properties.file ，value对应文件名称

log4jdbc.log4j2.properties.file=xxxx.properties

源码：

• net.sf.log4jdbc.Properties

可配置字段：

logger	描述
log4jdbc.spylogdelegator.name	spy日志处理类，默认为 net.sf.log4jdbc.log4j2.Log4j2SpyLogDelegator
log4jdbc.debug.stack.prefix	项目应用程序的包的部分或全部的前缀
log4jdbc.sqltiming.warn.threshold	执行SQL的时间长度（毫秒），在该时间段内，SQL需要至少运行这么长时间才能生成警告消息
log4jdbc.sqltiming.error.threshold	执行SQL的时间长度（毫秒），在该时间段内，SQL需要至少运行这么长时间才能生成错误消息
log4jdbc.dump.booleanastruefalse	boolean 值显示为 0 和 1 ，为 true 时 boolean 值显示为 true 和 false，默认false
log4jdbc.dump.sql.maxlinelength	SQL显示的最大长度，默认90
log4jdbc.dump.fulldebugstacktrace	在调试模式下是否转储完整堆栈跟踪，默认false
log4jdbc.statement.warn	使用statement（不是PreparedStatement）时，在日志中是否与SQL一起显示警告，默认false
log4jdbc.dump.sql.select	select语句是否输出，默认true
log4jdbc.dump.sql.insert	insert语句是否输出，默认true
log4jdbc.dump.sql.update	update语句是否输出，默认true
log4jdbc.dump.sql.delete	delete语句是否输出，默认true
log4jdbc.dump.sql.create	create语句是否输出，默认true
log4jdbc.dump.sql.addsemicolon	是否在 SQL 的行末添加一个分号，默认false
log4jdbc.auto.load.popular.drivers	是否自动选择最佳jdbc驱动，默认true
log4jdbc.drivers	jdbc驱动，String类型
log4jdbc.trim.sql	默认true
log4jdbc.trim.sql.extrablanklines	默认true
log4jdbc.suppress.generated.keys.exception	默认false

简单常用配置**（直接拿去用）**：

# 以下三个都需配置
# spy日志处理类
log4jdbc.spylogdelegator.name=net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator
# jdbc驱动（这里对应的mysql驱动版本为8.x）
log4jdbc.drivers=com.mysql.cj.jdbc.Driver
# 自动选择最佳jdbc驱动
log4jdbc.auto.load.popular.drivers=false


# 以下三个配置看自己需求了
# 设置的值为项目应用程序的包的部分或全部的前缀
log4jdbc.debug.stack.prefix=blog
# 当该值为 false 时，boolean 值显示为 0 和 1 ，为 true 时 boolean 值显示为 true 和 false
log4jdbc.dump.booleanastruefalse=true
# 是否在 SQL 的行末添加一个分号
log4jdbc.dump.sql.addsemicolon=true

（3）配置 logger

在 resources 目录下新建 logback.xml 文件（默认文件名）

如果需要自定义，可以在yaml中指定：

logging:
  config: classpath:xxxx.xml

配置上述的常用的 5大logger：（看自己实际需求配置了）

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds" debug="false">
    <contextName>BLOG</contextName>
    <property name="LOG_HOME" value="logs/%d{yyyy-MM,aux}/"/>
    <property name="LOG_" value="logs/"/>
    <property name="log.charset" value="utf-8"/>
    <property name="log.pattern"
              value="%black(%contextName-) %red(%d{yyyy-MM-dd HH:mm:ss}) %green([%thread]) %highlight(%-5level) %boldMagenta(%logger{36}) - %gray(%msg%n)"/>
    <!--输出到控制台-->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${log.pattern}</pattern>
            <charset>${log.charset}</charset>
        </encoder>
    </appender>

    <!-- 按照每天生成日志文件 -->
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${LOG_HOME}/server.%d{yyyy-MM-dd-HH}.log</FileNamePattern>
            <MaxHistory>60</MaxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>${log.pattern}</pattern>
            <charset>${log.charset}</charset>
        </encoder>
    </appender>

    <!--    监控sql日志输出-->
    <!--  如想看到表格数据，将OFF改为INFO  -->
    <logger name="jdbc.resultsettable" level="INFO" additivity="false">
        <appender-ref ref="console"/>
    </logger>
    <!--    包含 SQL 语句实际的执行时间 及sql语句（与jdbc.sqlonly功能重复）   -->
    <logger name="jdbc.sqltiming" level="INFO" additivity="false">
        <appender-ref ref="console"/>
    </logger>
    <!--      仅仅记录 SQL 语句，会将占位符替换为实际的参数-->
    <logger name="jdbc.sqlonly" level="OFF" additivity="false">
        <appender-ref ref="console"/>
    </logger>
    <!--  包含 ResultSet 的信息，输出篇幅较长  -->
    <logger name="jdbc.resultset" level="ERROR" additivity="false">
        <appender-ref ref="console"/>
    </logger>
    <!-- 输出了 Connection 的 open、close 等信息  -->
    <logger name="jdbc.connection" level="OFF" additivity="false">
        <appender-ref ref="console"/>
    </logger>
    <!--    除了 ResultSet 之外的所有JDBC调用信息，篇幅较长 -->
    <logger name="jdbc.audit" level="OFF" additivity="false">
        <appender-ref ref="console"/>
    </logger>

    <!--普通日志输出到控制台-->
    <root level="info">
        <appender-ref ref="console"/>
        <appender-ref ref="file"/>
    </root>
</configuration>

2.2、示例

上面配置好了，无需其他额外的配置，运行项目就可以直接看到相应的SQL执行情况，在控制台输出，输出的情况根据配置的情况有所不同

log4jdbc 原理

总结：其实底层还是调用logger（org.apache.logging.log4j.Logger / org.slf4j.Logger ）来实现日志记录，它的工作只是在执行sql的前后做了一些操作，将相应的内容进行输出

代码总览：

以下面的数据源与驱动配置来介绍一下我理解的原理：

db-type: com.alibaba.druid.pool.DruidDataSource
driverClassName: net.sf.log4jdbc.sql.jdbcapi.DriverSpy
url: jdbc:log4jdbc:mysql://${DB_HOST:localhost}:${DB_PORT:3306}/${DB_NAME:eladmin}?serverTimezone=Asia/Shanghai&characterEncoding=utf8&useSSL=false

以下为 debug 查看的相应执行流程：

（1）加载 DruidDataSource 数据源加载相应的驱动 net.sf.log4jdbc.sql.jdbcapi.DriverSpy，获取数据库连接

• net.sf.log4jdbc.sql.jdbcapi.DriverSpy

根据前缀，找到真实url的驱动：

static final private String log4jdbcUrlPrefix = "jdbc:log4";
// net.sf.log4jdbc.sql.jdbcapi.DriverSpy#getUnderlyingDriver
private Driver getUnderlyingDriver(String url) throws SQLException{
   if (url.startsWith(log4jdbcUrlPrefix)) {
      url = this.getRealUrl(url); // substring 前缀后的真实url
      Enumeration<Driver> e = DriverManager.getDrivers();
      Driver d;
      while (e.hasMoreElements()) {
         d = e.nextElement();
         if (d.acceptsURL(url)) {
            return d;
         }
      }
   }
   return null;
}

获取到 Connection / ConnectionSpy（包装JDBC连接），主要是根据5大logger是否有一个配置Error级别来决定返回类型

// net.sf.log4jdbc.sql.jdbcapi.DriverSpy#connect
@Override
public Connection connect(String url, java.util.Properties info) throws SQLException
{
   Driver d = getUnderlyingDriver(url); //获取到驱动
   if (d == null) {
      return null;
   }
   // 真实url,substring前缀后的url
   url = this.getRealUrl(url);

   lastUnderlyingDriverRequested = d;
   long tstart = System.currentTimeMillis();
   // 根据log4jdbc.log4j2.properties 中指定的 log4jdbc.drivers 进行connect (com.mysql.cj.jdbc.Driver)
   Connection c = d.connect(url, info); 

   if (c == null) {
      throw new SQLException("invalid or unknown driver url: " + url);
   }
   if (log.isJdbcLoggingEnabled()) { // 如果5大logger有配置leverl为Error级别的就为true
      ConnectionSpy cspy = new ConnectionSpy(c, System.currentTimeMillis() - tstart, log); // 包装JDBC连接并报告方法调用、返回和异常。
      RdbmsSpecifics r = null;
      String dclass = d.getClass().getName(); // 指定的 log4jdbc.drivers name
      if (dclass != null && dclass.length() > 0){
         r = rdbmsSpecifics.get(dclass);
      }
       // defaultRdbmsSpecifics为 net.sf.log4jdbc.sql.rdbmsspecifics.RdbmsSpecifics
      if (r == null){
         r = defaultRdbmsSpecifics; // 主要是封装特定关系数据库管理系统的sql格式细节，以便为该RDMBS编写准确、可用的sql。
      }
      cspy.setRdbmsSpecifics(r);
      return cspy;
   }
   return c;
}

（2）执行SQL 日志处理流程

真正执行SQL的时候，会在 包装Statement并报告方法调用、返回和异常 的xxxSpy来进行相应的SQL执行逻辑

• net.sf.log4jdbc.sql.jdbcapi.StatementSpy

以执行一条查询语句为例：

// net.sf.log4jdbc.sql.jdbcapi.StatementSpy 
@Override
public ResultSet executeQuery(String sql) throws SQLException
{
   String methodCall = "executeQuery(" + sql + ")";
   this.sql = sql;
   reportStatementSql(sql, methodCall); // SqlOnlyLogger记录
   long tstart = System.currentTimeMillis();
   try
   {
      ResultSet result = realStatement.executeQuery(sql); // 真正执行SQL
      reportStatementSqlTiming(System.currentTimeMillis() - tstart, sql, methodCall); // SqlTimingLogger记录
      ResultSetSpy r = new ResultSetSpy(this, result, this.log); 
      return (ResultSet) reportReturn(methodCall, r); // resultsetLogger记录
   }
   catch (SQLException s)
   {
      // 如果Logger配置了Error，即记录
      reportException(methodCall, s, sql, System.currentTimeMillis() - tstart);
      throw s;
   }
}

说明：

• 本质是执行sql的前后做了一些操作，利用对应的Logger将相应的内容进行输出
• 底层调用会根据指定的 log4jdbc.spylogdelegator.name 的相应 xxxDelegator 中的5大logger来进行记录
• 5大logger也是调用日志实现的相应slf4j或者log4j来实现日志打印/输出

相关链接

github log4jdbc

log4jdbc 官网