关于java:Mybatis的log机制

Mybatis的一个十分有用的附加性能就是能帮忙咱们打印执行过程中的log：sql语句、参数、执行后果等。这一个性在开发过程中十分有用，能够帮忙咱们疾速高效定位开发过程中的问题。

明天咱们从源码的角度钻研一下Mybatis的log机制，次要包含两局部：

Mybatis的日志框架
日志打印源码剖析，也就是找到Mybatis源码中打印日志的中央

日志框架#Log接口及其实现

目前java世界曾经有如下十分优良的日志框架：

Slf4j
CommonsLog
Log4J2
Log4J
JdkLog

Mybatis当然不会本人再实现一套日志框架，所谓Mybatis的日志框架，指的是Mybatis针对日志解决的外部实现，从而非常简单不便的反对上述各种支流日志框架。

首先，Mybatis定义了一个Log接口：

public interface Log {  boolean isDebugEnabled();  boolean isTraceEnabled();  void error(String s, Throwable e);  void error(String s);  void debug(String s);  void trace(String s);  void warn(String s);}

Log接口定义了4种log级别，和下面提到的Java支流log框架的日志级别对应。

Log接口有以下实现：

咱们能够看到，除了下面提到的针对java支流log框架的实现之外，Mybatis还提供了其余的Log接口的实现，都非常简单，比方StdOutImpl就是间接System.out.println或者System.err.println，NoLoggingImpl就是没有log的意思。

java支流日志框架的实现类其实也非常简单：创立相应java日志框架的log对象作为Mybatis日志对象的代理对象，Mybatis须要记录日志的时候，委派给代理对象执行。

日志框架#Log对象初始化

既然Mybatis反对各种java支流日志框架，那他到底是怎么决定具体应用哪个日志框架呢？其实就是Mybatis的log对象的初始化过程。

这个工作是LogFactory实现的。

  private static Constructor<? extends Log> logConstructor;    //...  private LogFactory() {    // disable construction  }

logFactory定义了一个动态Constructor变量logConstructor，并且把构造方法定义为private来阻止通过构造方法初始化，对外通过getLog办法提供Log对象：

  public static Log getLog(String logger) {    try {      return logConstructor.newInstance(logger);    } catch (Throwable t) {      throw new LogException("Error creating logger for logger " + logger + ".  Cause: " + t, t);    }  }

getLog办法也非常简单，间接通过结构器logConstructor调用newInstance办法获取Log对象。所以，LogFactory的外围其实就应该是这个logConstructor的初始化过程了。

持续看源码：

  static {    tryImplementation(LogFactory::useSlf4jLogging);    tryImplementation(LogFactory::useCommonsLogging);    tryImplementation(LogFactory::useLog4J2Logging);    tryImplementation(LogFactory::useLog4JLogging);    tryImplementation(LogFactory::useJdkLogging);    tryImplementation(LogFactory::useNoLogging);  }  ... private static void tryImplementation(Runnable runnable) {    if (logConstructor == null) {      try {        runnable.run();      } catch (Throwable t) {        // ignore      }    }  }  public static synchronized void useSlf4jLogging() {    setImplementation(org.apache.ibatis.logging.slf4j.Slf4jImpl.class);  }  public static synchronized void useCommonsLogging() {    setImplementation(org.apache.ibatis.logging.commons.JakartaCommonsLoggingImpl.class);  }

LogFactory定义了一个尝试创立日志实现对象的动态区，通过调用静态方法tryImplementation尝试创立日志对象，尝试的先后顺序就是咱们文章开篇列出的日志框架的程序，首先会尝试Slf4j、而后是CommonsLogging...最初应用NoLogging，不记录日志。

tryImplementation办法接管Runnable参数，调用的时候通过Lambda形式创立，别离指定为useSlf4jLogging()、useCommonsLogging()......等。通过调用setImplementation、传递相应的日志实现类参数，来创立对应的日志实现类。

setImplementation办法：

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("Logging initialized using '" + implClass + "' adapter.");      }      logConstructor = candidate;    } catch (Throwable t) {      throw new LogException("Error setting Log implementation.  Cause: " + t, t);    }  }

setImplementation创立日志实现类的结构器，只有该日志框架(比方Slf4j）的包引入到我的项目、创立该日志框架的日志对象胜利的话，就肯定可能获取到该日志对象的结构器，则将该结构器赋值给logConstructor。

这样，动态区6个tryImplementation办法的逻辑就分明了：依照调用程序，首先尝试初始化logConstructor为Slf4j的实现类，创立胜利的话，前面的调用就会被间接跳过、不会失效了。创立不胜利的话（比方Slf4j的包没有导入我的项目中）则尝试下一个......以此类推，最初肯定会创立进去适合的logConstructor。

除了动态区的tryImplementation办法的调用先后顺序来决定日志框架的优先级（到底是应用哪一个日志框架）之外，其实Mybatis还提供了另外两种手动设置日志框架的形式：

通过配置文件
代码中间接调用LocFactory.useCustomLogging

配置文件：

    <settings>        <setting name="cacheEnabled"             value="true" />  <!-- 全局映射器启用缓存 -->        <setting name="useGeneratedKeys"         value="true" />  <!-- 容许 JDBC 反对主动生成主键 -->        <setting name="defaultExecutorType"      value="REUSE" /> <!-- 配置默认的执行器 -->        <setting name="logImpl"                  value="SLF4J" /> <!-- 指定 MyBatis 所用日志的具体实现 -->        <!-- <setting name="mapUnderscoreToCamelCase" value="true"/>  驼峰式命名 -->    </settings>

配置文件指定的日志实现类是和typeAlias配合失效的，Configuration中实例化的时候曾经实现了注册：

typeAliasRegistry.registerAlias("SLF4J", Slf4jImpl.class);    typeAliasRegistry.registerAlias("COMMONS_LOGGING", JakartaCommonsLoggingImpl.class);    typeAliasRegistry.registerAlias("LOG4J", Log4jImpl.class);    typeAliasRegistry.registerAlias("LOG4J2", Log4j2Impl.class);    typeAliasRegistry.registerAlias("JDK_LOGGING", Jdk14LoggingImpl.class);    typeAliasRegistry.registerAlias("STDOUT_LOGGING", StdOutImpl.class);    typeAliasRegistry.registerAlias("NO_LOGGING", NoLoggingImpl.class);

配置文件在Mybatis初始化的过程中被读入，通过XMLConfigBuilder调用loadCustomLogImpl->Configuration.setLogImpl->LogFactory.useCustomLogging实现日志实现类的初始化。useCustomLogging办法代码咱们下面曾经看过了，间接调用setImplementation(clazz);办法无条件笼罩掉logConstructor，从而实现配置文件的最高优先级。

所以，决定Mybatis日志实现类（最终到底应用哪一个日志框架）的优先程序由低到高是：

LogFactory动态区tryImplementation调用程序指定
通过配置文件指定
用户代码中通过调用useCustomLogging随时指定，立刻失效

Mybatis的日志框架剖析实现，小结一下：Mybatis反对Java支流框架，包含Slf4j/CommonLogging/log4J2/log4J/JDKLoging/NoLogging/或者用户自定义Logging（应该没有人这么干吧）。用户能够通过配置文件或者在代码中指定具体应用哪一个日志框架，不指定的话Mybatis自行依照以上优先级一一尝试以后我的项目容许应用的日志框架（导入日志框架的包就能够应用）。

SQL语句打印

容许Mybatis打印SQL语句的配置也比较简单：在日志配置文件中指定关上针对mapper接口类的DEBUG级别的日志。比方，咱们我的项目中配置Mybatis应用Slf4j->logback作为日志框架，则须要在logback.xml做如下配置：

<logger name="com.myproject.mapper" level="debug" />

其中com.myproject.mapper是我的项目的mapper接口文件所在的包名称。

或者，基于Springboog的我的项目，间接在application.yml文件中增加：

logging:  level:    com.myproject.mapper: debug

配置的是mapper接口类的日志，顺着这个线索来找找Mybatis管制日志的代码：从Mapper接口登程。

后面的文章曾经剖析过了mapper.xml文件中的sql语句，初始化过程中被加载到Configuration中的mappedStatements中，最终被mapper接口的动静代理类通过调用MapperMethod的execute办法执行。

那咱们就间接看 MapperMethod的execute办法，咱们就以INSERT语句为代表：

 public Object execute(SqlSession sqlSession, Object[] args) {    Object result;    switch (command.getType()) {      case INSERT: {        Object param = method.convertArgsToSqlCommandParam(args);        result = rowCountResult(sqlSession.insert(command.getName(), param));        break;      }

看DefaultSqlSession的insert办法，始终追下去，最初调用到Executor的prepareStatement办法：

  private Statement prepareStatement(StatementHandler handler, Log statementLog) throws SQLException {    Statement stmt;    Connection connection = getConnection(statementLog);    stmt = handler.prepare(connection, transaction.getTimeout());    handler.parameterize(stmt);    return stmt;  }

这里看到了十分相熟的获取数据库连贯的语句，调用了getConnection（BaseExecutor中）办法：

  protected Connection getConnection(Log statementLog) throws SQLException {    Connection connection = transaction.getConnection();    if (statementLog.isDebugEnabled()) {      return ConnectionLogger.newInstance(connection, statementLog, queryStack);    } else {      return connection;    }  }

看到这里会判断statementLog.isDebugEnabled()，如果log关上了debug level的话，调用了ConnectionLogger.newInstance办法，去看一眼代码：

  public static Connection newInstance(Connection conn, Log statementLog, int queryStack) {    InvocationHandler handler = new ConnectionLogger(conn, statementLog, queryStack);    ClassLoader cl = Connection.class.getClassLoader();    return (Connection) Proxy.newProxyInstance(cl, new Class[]{Connection.class}, handler);  }

又是十分相熟的JDK动静代理，阐明返回的理论是数据库连贯的动静代理对象。

假相慢慢浮出水面了，咱们当初就要去认真钻研一下这个ConnectionLogger对象了，因为咱们要追究Mybatis日志的假相，这个类的名字切实太可疑了。

BaseJdbcLogger

Mybatis提供了一个叫BaseJdbcLogger的虚构类，专门用来提供数据库操作的日志记录能力，咱们先看一下类构造：

有4个实现类，别离对应Connection、Statement、PrepareStatement和Resultset，4个实现类都实现了InvocationHandler接口，充当了JDK动静代理的回调类，所有对被代理Connection、Statement、PrepareStatement、ResultSet对象的办法调用，都会回调到动静代理类的invoke办法上。

所以咱们间接看他们的invoke办法。

ConnectionLogger

间接看invoke办法：

@Override  public Object invoke(Object proxy, Method method, Object[] params)      throws Throwable {    try {      if (Object.class.equals(method.getDeclaringClass())) {        return method.invoke(this, params);      }      if ("prepareStatement".equals(method.getName()) || "prepareCall".equals(method.getName())) {        if (isDebugEnabled()) {          debug(" Preparing: " + removeExtraWhitespace((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);    }  }

看到了十分相熟的、常常在日志中呈现的内容“ Preparing：”，前面跟的就是要执行的sql语句。

而且，创立的prepareStatement之后，通过调用PreparedStatementLogger.newInstance创立代理对象，最终返回的是代理对象PreparedStatementLogger。

顺便说一句，咱们当初我的项目中绝大多数状况应该都是应用prepareStatement了，Mybatis反对在配置文件中指定statementType，然而个别状况下倡议不指定。不指定的话，默认也是PrepareStatement。所以绝大多数状况都是通过调用Connection的prepareStatement办法创立PrepareStatement的，日志里的Sql语句就是在这儿被打印的。

而且，下面咱们也从代码角度一路跟踪过去了，连贯创立以及statement的创立是mapper接口调用进来的，所以关上debug level的日志须要针对mapper包做配置。

PrepareStatementLogger

其实从日志追踪的角度看，代码就非常简单了：

 @Override  public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {    try {      if (Object.class.equals(method.getDeclaringClass())) {        return method.invoke(this, params);      }      if (EXECUTE_METHODS.contains(method.getName())) {        if (isDebugEnabled()) {          debug("Parameters: " + getParameterValueString(), true);        }        clearColumnInfo();        if ("executeQuery".equals(method.getName())) {          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())) {        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())) {        ResultSet rs = (ResultSet) method.invoke(statement, params);        return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);      } else if ("getUpdateCount".equals(method.getName())) {        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);    }  }

同样，日志中十分相熟的“Parameters ， Updates:”等内容呈现了。

如果是executeQuery办法调用、须要返回ResultSet的话，通过ResultSetLogger.newInstance办法创立并返回ResultSet的代理对象ResultSetLogger。

ResultSetLogger

和ConnectionLoger、PreparedStatementLogger的invoke办法大同小异：

 @Override  public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {    try {      if (Object.class.equals(method.getDeclaringClass())) {        return method.invoke(this, params);      }      Object o = method.invoke(rs, params);      if ("next".equals(method.getName())) {        if ((Boolean) o) {          rows++;          if (isTraceEnabled()) {            ResultSetMetaData rsmd = rs.getMetaData();            final int columnCount = rsmd.getColumnCount();            if (first) {              first = false;              printColumnHeaders(rsmd, columnCount);            }            printColumnValues(columnCount);          }        } else {          debug("     Total: " + rows, false);        }      }      clearColumnInfo();      return o;    } catch (Throwable t) {      throw ExceptionUtil.unwrapThrowable(t);    }  }

调用ResultSet的next办法获取数据的过程中累加记录条数，获取数据完结后log打印记录数。

如果日志级别设置为TRACE，则ResultSetLogger会打印获取到的数据后果，内容会很多，一般来讲也没有什么意义，倡议即便测试环境也不关上。

总结

通过对Mybatis的log框架源码的剖析，咱们晓得了Mybatis日志的前因后果，SQL语句的打印是DEBUG级别的，正式环境下咱们个别不会开DEBUG级别的日志，非凡状况须要察看正式环境下的SQL语句执行状况的话，能够只开启mapper接口的DEBUG日志。

上一篇连接池 Druid （补充） - removeAbandoned