Mybatis: See the whole process from Log

>>>> 😜😜😜 Github: 👉 github.com/black-ant CASE Backup: 👉 gitee.com/antblack/ca…

A. The preface

I haven’t paid attention to Mybatis source code for a long time. Recently, I encountered some problems with Mybatis at work, so I spent some time to sort out Mybatis notes for the convenience of troubleshooting problems in the future

This chapter starts with a small link to gradually expand the processing process of Mybatis

2. Logger triggers the flow

For example, in a Query process, you can print SQL logs to determine the execution of the SQL. Take a common SQL print as an example:

JDBC Connection [HikariProxyConnection@2034411604 wrapping com.mysql.cj.jdbc.ConnectionImpl@53b8afea] will not be managed by Spring
==>  Preparing: select sn, username, `password`, `power`, utype, isactive , age from user 
==> Parameters: 
<==    Columns: sn, username, password, power, utype, isactive, age
<==        Row: 0.22.33.44.null.null.1
<==        Row: 1.1.1.1.1.1.null
<==      Total: 2
Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@64355120]
Copy the code

So what does the overall trigger flow look like? In fact, you can see the whole process by viewing the Log process, which includes:

Connection creation: Connection object information, what Connection pool to use, Connection objects, etc.
SQL statement generation: what SQL is used for the operation, placeholder characteristics
Parameter processing: Query the parameters used
ROW print: Colums and ROW results of the query
Calculation of total queries: The total number of current queries
Session closing: The additional processing, operations, and type of Session used

The printing of each Log usually means the completion of a processing node. The following is a look at the whole processing process:

Yellow is the log printing process, it can be seen that it runs through the whole Mybatis process.

Added: Log implementation class

Log core interface, commonly used to achieve the following

StdOutImpl: implements the Log interface, StdOut implementation class, implements the C-slf4jimpl based on System. Out and System. Err: Implement the Log interface, Slf4j implementation class, MC - Slf4jImpl, constructor initializes the object | - logger. GetClass (). GetMethod | - will pass2Way to generate concrete classes | - org. Apache. Ibatis. Logging. Slf4j. Slf4jLocationAwareLoggerImpl | -newSlf4jLocationAwareLoggerImpl (LocationAwareLogger logger) | - org. Apache. Ibatis. Logging. Slf4j. Slf4jLoggerImpl class M - error / warn/info/debug methods such as direct call log. The XXX C - BaseJdbcLogger | - log the JDBC package, has the following implementation class | - based on JDBC interface implementation to strengthen case, and in principle, Dynamic proxy is also implemented based on the JDK// Other Logger implementation classes
C- BaseJdbcLogger
C- ConnectionLogger
C- PreparedStatementLogger
C- StatementLogger
C- ResultSetLogger
Copy the code

Supplement: LogFactory

In the Mc-constructor, the logConstructor property is initialized, where tryImplementation(Runnable Runnable) is implemented on the various implementations, Determine which implementation can use | - tryImplementation (LogFactory: : useSlf4jLogging); M-useslf4jlogging: Call #setImplementation(Class<? Extends the Log > the implClass) method, try to use the specified Log implementation class | -newInstance to create m-USecustomlogging (Class<? Extends the Log > clazz) method, set the custom Log implementation class M - getLog: get the Log object | - logConstructor. NewInstance * *Copy the code

Log Processing details

Here’s a quick look at the whole log process:

3.1 Printing Connection Information

In order to adapt to various log frameworks, Mybatis implements many implementation classes based on the log interface. The core processing includes BaseJdbcLogger and its four subclasses. The function is to print JDBC operations to logs through JDK dynamic proxy. There is also the factory class LogFactory

GetConnection operation triggered when SpringManagedTransaction gets connection information >>

private void openConnection(a) throws SQLException {
  
  // Get the connection and transaction auto-commit configuration
  this.connection = DataSourceUtils.getConnection(this.dataSource);
  this.autoCommit = this.connection.getAutoCommit();
  this.isConnectionTransactional = DataSourceUtils.isConnectionTransactional(this.connection, this.dataSource);
  
// Prints JDBC Connection information
  if (LOGGER.isDebugEnabled()) {
    LOGGER.debug(
        "JDBC Connection ["
            + this.connection
            + "] will"
            + (this.isConnectionTransactional ? "" : " not ")
            + "be managed by Spring"); }}Copy the code

3.2 Printing SQL Information

// S1: ConnectionLogger agent entry
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())) {
      if (isDebugEnabled()) {
        debug(" Preparing: " + removeBreakingWhitespace((String) params[0]), true);
      }        
      // Reflection gets PreparedStatement
      PreparedStatement stmt = (PreparedStatement) method.invoke(connection, params);
      stmt = PreparedStatementLogger.newInstance(stmt, statementLog, queryStack);
      return stmt;
    } else if ("prepareCall".equals(method.getName())) {
      / / print the Log
      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 {
      returnmethod.invoke(connection, params); }}catch (Throwable t) {
    throwExceptionUtil.unwrapThrowable(t); }}// S2: calls the concrete Log implementation class
protected void debug(String text, boolean input) {
  if(statementLog.isDebugEnabled()) { statementLog.debug(prefix(input) + text); }}Copy the code

triggered

S1: entry
  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;
  }


// S2: SQL print logic PreparedStatementHandler
  protected Statement instantiateStatement(Connection connection) throws SQLException {
    String sql = boundSql.getSql();
    if (mappedStatement.getKeyGenerator() instanceof Jdbc3KeyGenerator) {
      String[] keyColumnNames = mappedStatement.getKeyColumns();
      if (keyColumnNames == null) {
        return connection.prepareStatement(sql, PreparedStatement.RETURN_GENERATED_KEYS);
      } else {
        // Connection here actually calls ConnectionLogger
        returnconnection.prepareStatement(sql, keyColumnNames); }}else if(mappedStatement.getResultSetType() ! =null) {
      return connection.prepareStatement(sql, mappedStatement.getResultSetType().getValue(), ResultSet.CONCUR_READ_ONLY);
    } else {
      returnconnection.prepareStatement(sql); }}Copy the code

3.3 Printing the Select result

The query results are printed in the ResultSetLogger and the data structure is displayed

public Object invoke(Object proxy, Method method, Object[] params) throws Throwable {
    // Invoke returns a Boolean object when its method is next()
    Object o = method.invoke(rs, params);
    if ("next".equals(method.getName())) {
      if (((Boolean) o)) {
        // The number of lines increases by one
        rows++;
        if (isTraceEnabled()) {
          ResultSetMetaData rsmd = rs.getMetaData();
          final int columnCount = rsmd.getColumnCount();
          // If it is the first, the request header, the field name, is printed
          if (first) {
            first = false;
            printColumnHeaders(rsmd, columnCount);
          }
          // Prints field valuesprintColumnValues(columnCount); }}else {
        // If next returns false, next does not exist and prints the result
        debug(" Total: " + rows, false);
      }
    }
    clearColumnInfo();
    return o;
}
Copy the code

ResultSetMetaData Data structure

3.4 Printing Close Session

In SqlSessionInterceptor Finally, Close is finally called to Close the Session

public static void closeSqlSession(SqlSession session, SqlSessionFactory sessionFactory) {
  notNull(session, NO_SQL_SESSION_SPECIFIED);
  notNull(sessionFactory, NO_SQL_SESSION_FACTORY_SPECIFIED);

  / / SqlSessionHolder used in current TransactionSynchronizationManager maintain the Session
  SqlSessionHolder holder = (SqlSessionHolder) TransactionSynchronizationManager.getResource(sessionFactory);
  if((holder ! =null) && (holder.getSqlSession() == session)) {
    if (LOGGER.isDebugEnabled()) {
      LOGGER.debug("Releasing transactional SqlSession [" + session + "]");
    }
    // If SqlSessionHolder is used, it will be released directly
    holder.released();
  } else {
    if (LOGGER.isDebugEnabled()) {
      LOGGER.debug("Closing non transactional SqlSession [" + session + "]");
    }
    // If there is no transaction, close the sessionsession.close(); }}Copy the code

conclusion

I have roughly understood the processing process of Mybatis from the Log. Now I will go into details and learn how to extend and customize

Mybatis: See the whole process from Log

A. The preface

2. Logger triggers the flow

Log Processing details

3.1 Printing Connection Information

3.2 Printing SQL Information

3.3 Printing the Select result

3.4 Printing Close Session

conclusion

Related Posts

Functions related to system information about the current PHP script runtime

Go learning 8: package access, variable scope, closures

Java keyboard input statement Scanner