Mybatis 源码学习(11)-日志模块

历史文章：
Mybatis 源码学习(10)-类型转换（TypeAliasRegistry）

---

Java 开发中常用的日志工具类包括Log4J、Log4J2、Apache Common Log、java.util.logging、Slf4j，这些工具的接口并不统一，为了提供统一的接口，Mybatis 对这些日志接口做了统一适配。

Mybatis 的日志模块使用了适配器模式，其内部提供了统一的适配器接口：org.apache.ibatis.logging.Log，通过实现对接不同的第三方日志组件，实现多个 Adapter，从而将第三方组件适配成 org.apache.ibatis.logging.Log 对象，这样 Mybatis 内部就可以统一通过 org.apache.ibatis.logging.Log 接口调用第三方组件。

日志适配器

前面已经提到，第三方日志组件各自具有自己的日志级别，如 java.util.logging 包含 ALL、FINEST、FINER、FINE、CONFIG、INFO、WARNING、SEVERE、OFF 这 9 种日志级别，而 Log4j2 则只有 trace、debug、info、warn、error、fatal 这 6 种日志级别。Mybatis 仅支持 trace、debug、warn、error 这四种级别的日志。

Mybatis 的日志模块位于 org.apache.ibatis.logging 包内，通过 Log 接口对外提供功能，LogFactory 工厂类对外提供日志组件适配功能。

LogFactory 工厂类，使用其内部的静态代码初识化日志适配器，并使用 LogFactory.logConstructor 记录首个适配成功的日志适配器。

// 记录第一个搜索到的日志组件的构造器
private static Constructor<? extends Log> logConstructor;

static {
  // 针对每种日志组件尝试加载，默认顺序是：
  // useSlf4jLogging ->useCommonsLogging -> useLog4J2Logging ->
  // useLog4JLogging -> useJdkLogging -> useNoLogging
  tryImplementation(new Runnable() {
    @Override
    public void run() {
      useJdkLogging();
    }
  });
  // … 省略其他方法
}

LogFactory.tryImplementation 方法会检查是否已查找到可以日志适配器，如果尚未找到，则使用 Runnable.run 尝试加载对应的日志适配器，尝试失败则忽略异常，尝试成功则记录下该日志适配器的构造器。

// 尝试加载
private static void tryImplementation(Runnable runnable) {
  if (logConstructor == null) { // 未找到时，才允许加载
    try {
      runnable.run();
    } catch (Throwable t) {
      // 忽略所有异常
    }
  }
}

// 加载 Slf4
public static synchronized void useJdkLogging() {
  setImplementation(org.apache.ibatis.logging.jdk14.Jdk14LoggingImpl.class);
}

private static void setImplementation(Class<? extends Log> implClass) {
  try {
    // 获取指定适配器的构造函数
    Constructor<? extends Log> candidate = implClass.getConstructor(String.class);
    // 实例化适配器
    Log log = candidate.newInstance(LogFactory.class.getName());
    if (log.isDebugEnabled()) {
      log.debug(“…”);
    }
    // 如果加载正常，则初始化 logConstructor
    logConstructor = candidate;
  } catch (Throwable t) {
    throw new LogException(“…”);
  }
}

Jdk14LoggingImpl 实现了 org.apache.ibatis.logging.Log 接口，并封装了 java.util.logging.Logger，所有的日志操作，均由 java.util.logging.Logger 实现。

public class Jdk14LoggingImpl implements Log {

  private final Logger log; // 封装 java.util.logging.Logger 对象

  public Jdk14LoggingImpl(String clazz) {
    log = Logger.getLogger(clazz); // 初始化 java.util.logging.Logger 对象
  }

   // 所有的日志请求都由 java.util.logging.Logger 进行操作
  @Override
  public void debug(String s) {
    log.log(Level.FINE, s);
  }

  @Override
  public void warn(String s) {
    log.log(Level.WARNING, s);
  }
  // … 忽略其他方法
}

其他几个日志适配器的逻辑和 Jdk14LoggingImpl 的逻辑类似。

JDBC 日志功能

除了基本的日志适配外，Mybatis 还提供了 org.apache.ibatis.logging.jdbc 包，这个包提供了 SQL 日志调试功能，可以打印 SQL 语句、SQL 参数、结果集的内容以及行数。该目录下的 BaseJdbcLogger 是所有 SQL 日志类的基类，内部定义了 SET_METHODS、EXECUTE_METHODS 两个集合，用于记录 PreparedStatement 执行的方法和设置参数的方法（set* 方法）。

BaseJdbcLogger 内的两个集合的定义：

// PreparedStatement 接口定义的 set*() 方法集合
protected static final Set<String> SET_METHODS = new HashSet<String>();
// 记录 Statement 和 PreparedStatement 执行 SQL 的方法集合
protected static final Set<String> EXECUTE_METHODS = new HashSet<String>();

// 初始化两个集合
static {
  SET_METHODS.add("setString");
  SET_METHODS.add("setNString");
  SET_METHODS.add("setInt");
  // … 省略其他 set*() 方法

  EXECUTE_METHODS.add("execute");
  EXECUTE_METHODS.add("executeUpdate");
  EXECUTE_METHODS.add("executeQuery");
  EXECUTE_METHODS.add("addBatch");
}

BaseJdbcLogger 的核心字段定义如下：

// 记录 PreparedStatement.set*() 方法设置的键值对
private final Map<Object, Object> columnMap = new HashMap<Object, Object>();
// 记录 PreparedStatement.set*() 方法设置的 key
private final List<Object> columnNames = new ArrayList<Object>();
// 记录 PreparedStatement.set*() 方法设置的 value
private final List<Object> columnValues = new ArrayList<Object>();

BaseJdbcLogger 提供的工具方法会在后边继续分析，继续分析 ConnectionLogger，ConnectionLogger 是 BaseJdbcLogger 的子类，也是基于 JDK 的代理，它实现了 InvocationHandler 接口。ConnectionLogger.newInstance 方法会封装对应的 Connection 对象，并创建对应的代理对象 —— ConnectionLogger。

public static Connection newInstance(Connection conn, Log statementLog, int queryStack) {
  // 传入 Connection 对象，并创建 InvocationHandler
  InvocationHandler handler = new ConnectionLogger(conn, statementLog, queryStack);
  ClassLoader cl = Connection.class.getClassLoader();
  // 创建 Connection 的代理对象
  return (Connection) Proxy.newProxyInstance(cl, new Class[]{Connection.class}, handler);
}

ConnectionLogger.invoke 是实际执行 Connection 方法的具体实现，它会拦截 prepareStatement、prepareCall、createStatement 方法并执行实际的 Connection 的方法。

public Object invoke(Object proxy, Method method, Object[] params)
    throws Throwable {
  try {
    // 如果调用的是继承自 Object 的方法，则直接执行
    if (Object.class.equals(method.getDeclaringClass())) {
      return method.invoke(this, params);
    }
    // 拦截 prepareStatement、prepareCall、createStatement 方法，
    // 并为 Statement 创建对应的代理对象
    if ("prepareStatement".equals(method.getName())) {
      if (isDebugEnabled()) {
        debug(" Preparing: " + removeBreakingWhitespace((String) params[0]), true);
      }
      // 实际执行底层 Connection.prepareStatement 方法，获取 PreparedStatement 对象
      PreparedStatement stmt = (PreparedStatement) method.invoke(connection, params);
      // 为该 PreparedStatement 创建代理对象
      stmt = PreparedStatementLogger.newInstance(stmt, statementLog, queryStack);
      return stmt;
    } else if ("prepareCall".equals(method.getName())) {
      if (isDebugEnabled()) {
        debug(" Preparing: " + removeBreakingWhitespace((String) params[0]), true);
      }        
      PreparedStatement stmt = (PreparedStatement) method.invoke(connection, params);
      stmt = PreparedStatementLogger.newInstance(stmt, statementLog, queryStack);
      return stmt;
    } else if ("createStatement".equals(method.getName())) {
      Statement stmt = (Statement) method.invoke(connection, params);
      stmt = StatementLogger.newInstance(stmt, statementLog, queryStack);
      return stmt;
    } else {
      // 对其他方法，则直接调用，不进行代理
      return method.invoke(connection, params);
    }
  } catch (Throwable t) {
    throw ExceptionUtil.unwrapThrowable(t);
  }
}

PreparedStatementLogger 也继承自 BaseJdbcLogger，并实现了 InvocationHandler，它的 newInstance 方法也创建了代理对象。PreparedStatementLogger.invoke 方法会为 EXECUTE_METHODS 集合、SET_METHODS 集合、getResultSet 方法、getUpdateCount 方法进行代理。

public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {
  try {
    // 直接调用 Object 的方法
    if (Object.class.equals(method.getDeclaringClass())) {
      return method.invoke(this, params);
    }
    // 调用执行类方法
    if (EXECUTE_METHODS.contains(method.getName())) {
      if (isDebugEnabled()) {
        debug("Parameters: " + getParameterValueString(), true);
      }
      clearColumnInfo(); // 清空 BaseJdbcLogger 中记录的三个参数集合
      if ("executeQuery".equals(method.getName())) {
        // 如果执行的是 executeQuery 则为 ResultSet 创建代理对象
        // 其他 execute* 方法的返回值不是 ResultSet
        ResultSet rs = (ResultSet) method.invoke(statement, params);
        return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);
      } else {
        // 其他情况，直接返回结果
        return method.invoke(statement, params);
      }
    } else if (SET_METHODS.contains(method.getName())) {
      // 调用 SET_METHODS 中记录的 set*() 方法设置参数，则需要通过 setColumn 方法记录对应的参数
      if ("setNull".equals(method.getName())) {
        setColumn(params[0], null);
      } else {
        setColumn(params[0], params[1]);
      }
      return method.invoke(statement, params);
    } else if ("getResultSet".equals(method.getName())) {
      // 如果是 getResultSet 方法，则创建 ResultSet 代理
      ResultSet rs = (ResultSet) method.invoke(statement, params);
      return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);
    } else if ("getUpdateCount".equals(method.getName())) {
      // 如果调用 getUpdateCount 方法，则直接输出更新影响的行数
      int updateCount = (Integer) method.invoke(statement, params);
      if (updateCount != -1) {
        debug("   Updates: " + updateCount, false);
      }
      return updateCount;
    } else {
      return method.invoke(statement, params);
    }
  } catch (Throwable t) {
    throw ExceptionUtil.unwrapThrowable(t);
  }
}

StatementLogger 和 PreparedStatementLogger 的实现类似，但是它不允许设置参数，因此不会拦截 SET_METHODS 记录的设置参数的方法。
ResultSetLogger 封装了 ResultSet，也继承自 BaseJdbcLogger，实现了 InvocationHandler。它的主要字段如下：

private boolean first = true; // 是否是 ResultSet 的第一行
private int rows; // 影响行数
private final ResultSet rs; // 实际的 ResultSet
private final Set<Integer> blobColumns = new HashSet<Integer>(); // 记录超长字段的下标

// 长度超长的字段
private static Set<Integer> BLOB_TYPES = new HashSet<Integer>();
static {
  BLOB_TYPES.add(Types.BINARY);
  // … 添加其他类型：Types.BLOB、Types.CLOB、Types.LONGNVARCHAR、
  // Types.LONGVARBINARY、Types.LONGVARCHAR、Types.NCLOB、Types.VARBINARY
}

ResultSetLogger.newInstance 也只是在创建代理对象，ResultSetLogger.invoke 方法会拦截 ResultSet 的 next() 方法，并解析列名和参数值，输出到日志里。

public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {
  try {
    // 直接转发继承自 Object 的方法
    if (Object.class.equals(method.getDeclaringClass())) {
      return method.invoke(this, params);
    }
    Object o = method.invoke(rs, params);
    // 对 next 方法进行拦截
    if ("next".equals(method.getName())) {
      if (((Boolean) o)) { // 是否存在下一行
        rows++;
        if (isTraceEnabled()) {
          ResultSetMetaData rsmd = rs.getMetaData(); // 获取表头
          final int columnCount = rsmd.getColumnCount(); // 获取行数
          if (first) {
            first = false;
            // 输出表头，并将超长字段记录到 blobColumns 中
            printColumnHeaders(rsmd, columnCount);
          }
          // 输出本行内容，但是特殊展示超长字段
          printColumnValues(columnCount);
        }
      } else { // 打印总共影响的行数
        debug("     Total: " + rows, false);
      }
    }
    clearColumnInfo(); // 清除 BaseJdbcLogger 记录的参数集合
    return o;
  } catch (Throwable t) {
    throw ExceptionUtil.unwrapThrowable(t);
  }
}

总结

日志适配器的逻辑不算复杂，它使用 LogFactory 作为工厂类创建对应的日志适配器，而 Log 类提供了日志适配器的接口。在进行日志加载时，是按照既定的顺序执行的，即如果查找到第一个可用适配器时，就不会使用后面的适配器了。至于为什么尝试加载使用 Runnable.run，这是为了方便，不再新定义操作接口。另外，如果 LogFactory 加载了 classpath 中没有的日志类，tryImplementation 会忽略掉错误，继续加载后边的日志适配器。

JDBC 类型的日志关键在于为每种 JDBC 操作对象创建 InvocationHandler 代理对象，代理对象会拦截每个操作，并根据方法名称和操作结果生成对应日志信息。


参考文档：《Mybatis 技术内幕》

本文的基本脉络参考自《Mybatis 技术内幕》，编写文章的原因是希望能够系统地学习 Mybatis 的源码，但是如果仅阅读源码或者仅从官方文档很难去系统地学习，因此希望参考现成的文档，按照文章的脉络逐步学习。

---

欢迎关注我的公众号：我的搬砖日记，我会定时分享自己的学习历程。