Log printing principle of Mybatis

1. Mybatis log start and source code analysis

Log on

This type of log printing is the simplest, using standard output and error output. If you use other logging frameworks, the name and value are different from here. So let’s start with that. This will be explained below

<settings>
     <setting name="logImpl" value="STDOUT_LOGGING" />
</settings>
Copy the code

Source code analysis

Mybatis starts with XML file parsing.

As long as DEBUG starts from creating the SqlSessionFactory, you can see the parse action

  sqlMapper = new SqlSessionFactoryBuilder().build(reader);

/ / the debug
private void parseConfiguration(XNode root) {
    try {
      // issue #117 read properties first
      propertiesElement(root.evalNode("properties")); // Parse the properties tag and place it in the Variables of Parser and config
      
       // Parse the Settings tag. And change the Properties and values inside to Properties and verify that there are Properties.
      Properties settings = settingsAsProperties(root.evalNode("settings"));// Load the setting TAB
      
      loadCustomVfs(settings); // what is the VFS in lcnote? How do I know this
      VFS (virtual File System) abstracts several apis to access resources on the file system; For example, in
      // Parse mapperElement(root.evalNode("mappers")); If you specify package, you can get all the class files under the package path through the VFS.
      // It will be added to mappe, similar to the classPathSacnner in Spring, which can specify filters.

    
      
      // Customize LogImpl
      loadCustomLogImpl(settings);
      typeAliasesElement(root.evalNode("typeAliases"));

      // From here on, we parse the specific tag, new out the object, set the attribute under the tag,
      Mybatis (mybatis) objectFactory (mybatis) objectFactory (mybatis) The objectFactory, plugins
      pluginElement(root.evalNode("plugins"));
      objectFactoryElement(root.evalNode("objectFactory"));
      objectWrapperFactoryElement(root.evalNode("objectFactory"));
      reflectorFactoryElement(root.evalNode("objectFactory"));

      // Set the setting tag
      settingsElement(settings);

      // read it after objectFactory and objectWrapperFactory issue #631
      environmentsElement(root.evalNode("environments"));
      databaseIdProviderElement(root.evalNode("databaseIdProvider"));
      typeHandlerElement(root.evalNode("typeHandlers"));

      //lcnote
      mapperElement(root.evalNode("mappers"));
    } catch (Exception e) {
      throw new BuilderException("Error parsing SQL Mapper Configuration. Cause: "+ e, e); }}Copy the code

loadCustomLogImpl

 private void loadCustomLogImpl(Properties props) {
    Class<? extends Log> logImpl = resolveClass(props.getProperty("logImpl"));
    configuration.setLogImpl(logImpl);
  }

The resolveClass method is determined by calling the resolveAlias of typeAliasRegistry
//TypeAliasRegistry is the TypeAliasRegistry
// Many types are injected by default during initialization. See the constructor of TypeAliasRegistry and Configuration for details.


    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);

Copy the code

After the corresponding entity class is parsed, the instance is created using LogFactory. The class object is assigned to the logImpl property of Configuration

LogFactory.useCustomLogging

 public void setLogImpl(Class<? extends Log> logImpl) {
    if(logImpl ! =null) {
      this.logImpl = logImpl;
      LogFactory.useCustomLogging(this.logImpl); }}// the method called in useCustomLogging
 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.");
      }
      
      // Notice that the Constructor found here is assigned to the logConstructor property of the LogFactory
      logConstructor = candidate;
    } catch (Throwable t) {
      throw new LogException("Error setting Log implementation. Cause: "+ t, t); }}Copy the code

Mybatis also supports the log prefix

    configuration.setLogPrefix(props.getProperty("logPrefix")); // The prefix can be set to log
// Can be set in setting.
 // The corresponding property is the logPrefix property of the Configuration
Copy the code

The logging implementation class is set here and also assigned to Configuration. So how does he use it? In the above code, after the instance is generated from LogFactory New, there is no assignment, it is allowed to log, and then it is finished, leaving only the constructor in LogFactory to create the instance. Nothing else, but in Mybatis logs look like this.

So, how does he do this?

Regardless of Mybatis implementation, to achieve such a function, the first thought is the section. Then came the creation of the proxy. In Mybatis, it is definitely not Spring. He used the JDK’s dynamic proxy.

Imagine generating proxy objects for the Statement and Result Next methods. The log can then be printed before the method is actually executed. That’s exactly what Mybatis does.

As a caveat, each class usually has a Logger object when logging. Notice that the Logger object is owned by every class.

So let’s see.

// SimpleExecutor##doQuery method.

@Override
  public <E> List<E> doQuery(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler, BoundSql boundSql) throws SQLException {
    Statement stmt = null;
    try {
      Configuration configuration = ms.getConfiguration();
      StatementHandler handler = configuration.newStatementHandler(wrapper, ms, parameter, rowBounds, resultHandler, boundSql);
      // This is the point. Create a Connection object inside it.
      // The ms StatementLog will be passed in.
      stmt = prepareStatement(handler, ms.getStatementLog());
      return handler.query(stmt, resultHandler);// Query and map result sets
    } finally{ closeStatement(stmt); }}Copy the code

MappedStatement is an entity class that corresponds to a method in a Mapper. This object is created when parsing XMl. The StatementLog attribute must also be set at this time.

Click through the prepareStatement method to see how to create a Connection object. As anyone who has written JDBC knows, this object is the start of a query.

Create a proxy object for Connection

  protected Connection getConnection(Log statementLog) throws SQLException {
    Connection connection = transaction.getConnection();
    // The code is simple. If true, a proxy object for Connection is created.
    // The StdOutImpl debugEnabled defaults to true.
    if (statementLog.isDebugEnabled()) {
      return ConnectionLogger.newInstance(connection, statementLog, queryStack);
    } else {
      returnconnection; }}Copy the code

ConnectionLogger.newInstance

  /**
   * Creates a logging version of a connection.
   *
   * @param conn
   *          the original connection
   * @param statementLog
   *          the statement log
   * @param queryStack
   *          the query stack
   * @return the connection with logging
   */
  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);
  }

// The JDK proxy is used to implement logging, and the JDK proxy is InvocationHandler. In this case, the ConnectionLogger
Copy the code

ConnectionLogger class details


public final class ConnectionLogger extends BaseJdbcLogger implements InvocationHandler {

  private final Connection connection;

  private ConnectionLogger(Connection conn, Log statementLog, int queryStack) {
    super(statementLog, queryStack);
    this.connection = conn;
  }

  @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 the method name is prepareStatement or prepareCall, the log is printed.
       // It is easy to print,
      if ("prepareStatement".equals(method.getName()) || "prepareCall".equals(method.getName())) {
        if (isDebugEnabled()) {
          // The debug method calls the BaseJdbcLogger statementLog attribute, which is in MapperStatement.
          debug(" Preparing: " + removeExtraWhitespace((String) params[0]), true);
        }
        // When a prepareStatement is called with Connection, a PreparedStatement is generated.
         // PreparedStatement is the BaseJdbcLogger implementation class.
        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 {
        returnmethod.invoke(connection, params); }}catch (Throwable t) {
      throwExceptionUtil.unwrapThrowable(t); }}}Copy the code

The first thing you can see is that it inherits BaseJdbcLogger, where the BaseJdbcLogger implementation class says it can print logs.

The BaseJdbcLogger class has two collections. One is SET_METHODS, which hold set methods in PreparedStatement with parameters greater than 1.

EXECUTE_METHODS holds the name for the execute executeUpdate, executeQuery, addBatch method

So let’s see what the ConnectionLoggerinvoke method does.

Comments are already written in the code above.

Create a proxy object for Statement

As you can see, it also inherits from BaseJdbcLogger and is an InvocationHandler, which must look at the Invoke method,

public final class StatementLogger extends BaseJdbcLogger implements InvocationHandler {

  private final Statement statement;

  private StatementLogger(Statement stmt, Log statementLog, int queryStack) {
    super(statementLog, queryStack);
    this.statement = stmt;
  }
  
  If the method name is executeQuery, the ResultSetLogger will be wrapped after the method is called and the ResultSet is generated. If the method name is ResultSet, wrap the generated ResultSet **/ after calling the method
  @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(" Executing: " + removeExtraWhitespace((String) params[0]), true);
        }
        if ("executeQuery".equals(method.getName())) {
          ResultSet rs = (ResultSet) method.invoke(statement, params);
          return rs == null ? null : ResultSetLogger.newInstance(rs, statementLog, queryStack);
        } else {
          returnmethod.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 {
        returnmethod.invoke(statement, params); }}catch (Throwable t) {
      throwExceptionUtil.unwrapThrowable(t); }}}Copy the code

Here the methods used to create objects are the same as the methods used to delegate objects. The steps are the same.

Create a proxy object for Result

It also inherits BaseJdbcLogger and implements InvocationHandler, again looking at the Invoke method.

BLOB_TYPES << Blob >> << Blob >> << Blob >> Print if you can. * * /
public final class ResultSetLogger extends BaseJdbcLogger implements InvocationHandler {

  private static final Set<Integer> BLOB_TYPES = new HashSet<>();
  private boolean first = true;
  private int rows;
  private final ResultSet rs;
  private final Set<Integer> blobColumns = new HashSet<>();

  static {
    BLOB_TYPES.add(Types.BINARY);
    BLOB_TYPES.add(Types.BLOB);
    BLOB_TYPES.add(Types.CLOB);
    BLOB_TYPES.add(Types.LONGNVARCHAR);
    BLOB_TYPES.add(Types.LONGVARBINARY);
    BLOB_TYPES.add(Types.LONGVARCHAR);
    BLOB_TYPES.add(Types.NCLOB);
    BLOB_TYPES.add(Types.VARBINARY);
  }

  private ResultSetLogger(ResultSet rs, Log statementLog, int queryStack) {
    super(statementLog, queryStack);
    this.rs = rs;
  }

  @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()) {
            // Get the ResultSet print result
            ResultSetMetaData rsmd = rs.getMetaData();
            final int columnCount = rsmd.getColumnCount();
            if (first) {
              first = false;
              // Prints header information
              printColumnHeaders(rsmd, columnCount);
            }
            // Prints a specific valueprintColumnValues(columnCount); }}else {
          / / a total
          debug(" Total: " + rows, false);
        }
      }
      clearColumnInfo();
      return o;
    } catch (Throwable t) {
      throwExceptionUtil.unwrapThrowable(t); }}private void printColumnHeaders(ResultSetMetaData rsmd, int columnCount) throws SQLException {
    StringJoiner row = new StringJoiner(","." Columns: "."");
    for (int i = 1; i <= columnCount; i++) {
      // If the type is BLOB, add it to blobColumns. Note that this adds the id of the column
      if (BLOB_TYPES.contains(rsmd.getColumnType(i))) {
        blobColumns.add(i);
      }
      row.add(rsmd.getColumnLabel(i));
    }
    trace(row.toString(), false);
  }
  << blobColumns >> << blobColumns
  private void printColumnValues(int columnCount) {
    StringJoiner row = new StringJoiner(","." Row: "."");
    for (int i = 1; i <= columnCount; i++) {
      try {
        if (blobColumns.contains(i)) {
          row.add("<<BLOB>>");
        } else{ row.add(rs.getString(i)); }}catch (SQLException e) {
        // generally can't call getString() on a BLOB column
        row.add("<<Cannot Display>>");
      }
    }
    trace(row.toString(), false); }}Copy the code

Here is the analysis of the end, Mybatis inside the log is how to print, and how to play a role.

Let’s take a look at how Mybatis integrates most logging together, and it also supports custom logging implementation classes.

3. Mybatis log analysis interface and implementation class analysis (source code analysis)

How and where is a MapperStatement created?

Created when the MapperStatement is created in the parsing Xml file

//MapperStatement inner class Builder method
    public Builder(Configuration configuration, String id, SqlSource sqlSource, SqlCommandType sqlCommandType) {
      mappedStatement.configuration = configuration;
      mappedStatement.id = id;
      mappedStatement.sqlSource = sqlSource;
      mappedStatement.statementType = StatementType.PREPARED;
      mappedStatement.resultSetType = ResultSetType.DEFAULT;
      mappedStatement.parameterMap = new ParameterMap.Builder(configuration, "defaultParameterMap".null.new ArrayList<>()).build();
      mappedStatement.resultMaps = new ArrayList<>();
      mappedStatement.sqlCommandType = sqlCommandType;
      mappedStatement.keyGenerator = configuration.isUseGeneratedKeys() && SqlCommandType.INSERT.equals(sqlCommandType) ? Jdbc3KeyGenerator.INSTANCE : NoKeyGenerator.INSTANCE;
      String logId = id;
      if(configuration.getLogPrefix() ! =null) {
        logId = configuration.getLogPrefix() + id;
      }
      // The point is here
      mappedStatement.statementLog = LogFactory.getLog(logId);
      mappedStatement.lang = configuration.getDefaultScriptingLanguageInstance();
    }
Copy the code

As discussed above, when parsing the Setting tag, the selected constructor to build the Log is kept in the LogFactory, which can then be used to create the Log object whenever the Log is created.

How does LogFactory create a Log object

// The getLog method of LogFactory creates the object using the previously reserved constructor
  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); }}Copy the code

Mybatis Log interface and implementation class (Log is how to merge common Log)

The Log interface

Define the Log interface, and it contains some common logging methods


/ * * *@author Clinton Begin
 */
public interface Log {
 
  boolean isDebugEnabled(a);

  boolean isTraceEnabled(a);

  void error(String s, Throwable e);

  void error(String s);

  void debug(String s);

  void trace(String s);

  void warn(String s);

}
Copy the code

The Log implementation class

You customize a Log interface and then use different logging frameworks in different implementation classes. The main idea is to create a concrete Logger object in the constructor and wrap this object in a custom implementation Logger interface, thus achieving unity. Adapter mode

In the XML`Setting`How to configure to use the above implementation class (how to use other logging frameworks)

The alias and type mappings are registered through typeAliasRegistry in the Configuration constructor

Look at two examples of concrete Log interface implementations

Both of these concrete examples are very simple.

StdOutImpl

This implementation is very simple, all call System normal and error output to print.

/* * Copyright 2009-2021 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the  License. */
package org.apache.ibatis.logging.stdout;

import org.apache.ibatis.logging.Log;

/ * * *@author Clinton Begin
 */
public class StdOutImpl implements Log {

  public StdOutImpl(String clazz) {
    // Do Nothing
  }

  @Override
  public boolean isDebugEnabled(a) {
    return true;
  }

  @Override
  public boolean isTraceEnabled(a) {
    return true;
  }

  @Override
  public void error(String s, Throwable e) {
    System.err.println(s);
    e.printStackTrace(System.err);
  }

  @Override
  public void error(String s) {
    System.err.println(s);
  }

  @Override
  public void debug(String s) {
    System.out.println(s);
  }

  @Override
  public void trace(String s) {
    System.out.println(s);
  }

  @Override
  public void warn(String s) { System.out.println(s); }}Copy the code

Log4jImpl

/* * Copyright 2009-2021 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the  License. */
package org.apache.ibatis.logging.log4j;

import org.apache.ibatis.logging.Log;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;

/ * * *@author Eduardo Macarron
 */
public class Log4jImpl implements Log {

  private static final String FQCN = Log4jImpl.class.getName();
  // This Logger is log4j's adaptor mode
  private final Logger log;

  public Log4jImpl(String clazz) {
    // The class passed in is the id of the MapperStatement
    log = Logger.getLogger(clazz);
  }

  @Override
  public boolean isDebugEnabled(a) {
    return log.isDebugEnabled();
  }

  @Override
  public boolean isTraceEnabled(a) {
    return log.isTraceEnabled();
  }

  @Override
  public void error(String s, Throwable e) {
    log.log(FQCN, Level.ERROR, s, e);
  }

  @Override
  public void error(String s) {
    log.log(FQCN, Level.ERROR, s, null);
  }

  @Override
  public void debug(String s) {
    log.log(FQCN, Level.DEBUG, s, null);
  }

  @Override
  public void trace(String s) {
    log.log(FQCN, Level.TRACE, s, null);
  }

  @Override
  public void warn(String s) {
    log.log(FQCN, Level.WARN, s, null); }}Copy the code

2. Customize logs

1. Implement the Log interface

package org.apache.ibatis.session.mybatis;

import org.apache.ibatis.logging.Log;

public class MyLog implements Log {
  public MyLog(String id){
    System.out.println("MyLog:"+id);
  }
  @Override
  public boolean isDebugEnabled(a) {
    return true;
  }

  @Override
  public boolean isTraceEnabled(a) {
    return true;
  }

  @Override
  public void error(String s, Throwable e) {
    System.out.println("MyLog:"+s);
    e.printStackTrace();
  }

  @Override
  public void error(String s) {
    System.out.println("MyLog:"+s);
  }

  @Override
  public void debug(String s) {
    System.out.println("MyLog:"+s);
  }

  @Override
  public void trace(String s) {
    System.out.println("MyLog:"+s);
  }

  @Override
  public void warn(String s) {
    System.out.println("MyLog:"+s); }}Copy the code

2. Configure the configuration file

Note that the custom value must be a fully qualified class name. An alias cannot be configured. In the code in the above section, Setting is parsed in front of typeAliases, so it cannot be configured through aliases.

3. Results presentation

You can see that the log starts with MyLog.

Mybatis log print analysis so far. Please point out any inaccuracies. thank you

Log printing principle of Mybatis

Log printing principle of Mybatis

1. Mybatis log start and source code analysis

Log on

Source code analysis

loadCustomLogImpl

LogFactory.useCustomLogging

Create a proxy object for Connection

ConnectionLogger.newInstance

ConnectionLogger class details

Create a proxy object for Statement

Create a proxy object for Result

3. Mybatis log analysis interface and implementation class analysis (source code analysis)

How and where is a MapperStatement created?

How does LogFactory create a Log object

Mybatis Log interface and implementation class (Log is how to merge common Log)

The Log interface

The Log implementation class

In the XMLSettingHow to configure to use the above implementation class (how to use other logging frameworks)

Look at two examples of concrete Log interface implementations

StdOutImpl

Log4jImpl

2. Customize logs

1. Implement the Log interface

2. Configure the configuration file

3. Results presentation

Related Posts

MySQL InnoDB storage engine: multi-table join query

Java Data Structures — Single linked Surfaces

Us group dynamic thread pool practice ideas, open source

In the XML`Setting`How to configure to use the above implementation class (how to use other logging frameworks)