【Log4j2】开发环境配置日志策略打印完整MyBatis语句到文件

前言

公司项目用的 Spring Boot，选用的是 Log4j2 作为日志实现，本地开发的时候没有把sql语句打印到文件中，并且控制台输出的sql需要自己拼接，看了log4j2官网后整理了个日志文件demo实现自己的需求。Logback作为 Spring Boot自动装配的默认实现，所以选用Log4j2 记得要排除掉默认依赖。

依赖

		<dependency>
			<groupId>org.springframework.bootgroupId>
			<artifactId>spring-boot-starter-webartifactId>
			<exclusions>
				<exclusion>
					<groupId>org.springframework.bootgroupId>
					<artifactId>spring-boot-starter-loggingartifactId>
				exclusion>
			exclusions>
		dependency>

		<dependency>
			<groupId>org.springframework.bootgroupId>
			<artifactId>spring-boot-starter-log4j2artifactId>
		dependency>
				<dependency>
			<groupId>org.mybatis.spring.bootgroupId>
			<artifactId>mybatis-spring-boot-starterartifactId>
			<version>2.2.2version>
		dependency>
		<dependency>
			<groupId>mysqlgroupId>
			<artifactId>mysql-connector-javaartifactId>
			<version>5.1.25version>
		dependency>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25

application.yml

这里习惯引用外部的配置文件

spring:
  datasource:
    url: jdbc:mysql://localhost:3306/james?useUnicode=true&characterEncoding=utf8&useSSL=false&serverTimezone=Asia/Shanghai
    username: root
    password: 123456
    driver-class-name: com.mysql.jdbc.Driver

mybatis:
  config-location: classpath:mybatis.xml 
  mapper-locations: classpath:mapper/*.xml 

logging:
  config: classpath:log4j2.xml
1
2
3
4
5
6
7
8
9
10
11
12
13

mybatis.xml

这个文件用于打印完整的sql语句，遵循mybatis的规范(接口)，对应的Java代码是摘录网上的。

DOCTYPE configuration
        PUBLIC "-//mybatis.org//DTD Config 3.0//EN"
        "http://mybatis.org/dtd/mybatis-3-config.dtd">
<configuration>
    <plugins>
        <plugin interceptor="com.james.usinglog.MybatisInterceptor"/>
    plugins>
configuration>
1
2
3
4
5
6
7
8
9

import java.text.DateFormat;
import java.util.Date;
import java.util.List;
import java.util.Locale;

import org.apache.ibatis.executor.Executor;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.MappedStatement;
import org.apache.ibatis.mapping.ParameterMapping;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Plugin;
import org.apache.ibatis.plugin.Signature;
import org.apache.ibatis.reflection.MetaObject;
import org.apache.ibatis.session.Configuration;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.RowBounds;
import org.apache.ibatis.type.TypeHandlerRegistry;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

@Intercepts({
        @Signature(type = Executor.class, method = "update", args = { MappedStatement.class, Object.class }),
        @Signature(type = Executor.class, method = "query", args = { MappedStatement.class, Object.class,
                RowBounds.class, ResultHandler.class }) })
public class MybatisInterceptor implements Interceptor {

    Logger LOGGER = LoggerFactory.getLogger(MybatisInterceptor.class);

    public Object intercept(Invocation invocation) throws Throwable {
        MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0];
        Object parameter = null;
        if (invocation.getArgs().length > 1) {
            parameter = invocation.getArgs()[1];
        }
        String sqlId = mappedStatement.getId();
        BoundSql boundSql = mappedStatement.getBoundSql(parameter);
        Configuration configuration = mappedStatement.getConfiguration();
        Object returnValue = null;
        long start = System.currentTimeMillis();
        returnValue = invocation.proceed();
        long end = System.currentTimeMillis();
        long time = (end - start);
        if (time > 1) {
            String sql = showSql(configuration, boundSql);
            LOGGER.warn(">> {}", sql);
        }
        return returnValue;
    }
 
    private static String getParameterValue(Object obj) {
        String value = null;
        if (obj instanceof String) {
            value = "'" + obj + "'";
        } else if (obj instanceof Date) {
            DateFormat formatter = DateFormat.getDateTimeInstance(DateFormat.DEFAULT, DateFormat.DEFAULT, Locale.CHINA);
            value = "'" + formatter.format(new Date()) + "'";
        } else {
            if (obj != null) {
                value = obj.toString();
            } else {
                value = "";
            }
 
        }
        return value;
    }
 
    public static String showSql(Configuration configuration, BoundSql boundSql) {
        Object parameterObject = boundSql.getParameterObject();
        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();
        String sql = boundSql.getSql().replaceAll("[\\s]+", " ");
        if (parameterMappings.size() > 0 && parameterObject != null) {
            TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();
            if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {
                sql = sql.replaceFirst("\\?", getParameterValue(parameterObject));
 
            } else {
                MetaObject metaObject = configuration.newMetaObject(parameterObject);
                for (ParameterMapping parameterMapping : parameterMappings) {
                    String propertyName = parameterMapping.getProperty();
                    if (metaObject.hasGetter(propertyName)) {
                        Object obj = metaObject.getValue(propertyName);
                        sql = sql.replaceFirst("\\?", getParameterValue(obj));
                    } else if (boundSql.hasAdditionalParameter(propertyName)) {
                        Object obj = boundSql.getAdditionalParameter(propertyName);
                        sql = sql.replaceFirst("\\?", getParameterValue(obj));
                    }
                }
            }
        }
        return sql;
    }
 
    public Object plugin(Object target) {
        return Plugin.wrap(target, this);
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99

log4j2.xml

为指定文件/包定制日志级别

开发阶段不想看到满屏幕的日志，可以把日志级别控制到 info ，对于自己想要详细打日志的类，则另外指定；
借用的是 官网的继承体系 ，跟logback很像 。

• 全局日志级别

        <Root level="info">
            <AppenderRef ref="MyFile"/>
        Root>
1
2
3

• 只看自己项目内的debug日志

        <Logger name="com.james" level="debug" additivity="false">
            <AppenderRef ref="MyFile"/>
        Logger>
1
2
3

• 让Mybatis打印的sql语句声明为 warn
  这里是借鉴了阿里把用户输入请求打印成warn方便检索。同时可以在idea配置warn日志高亮。

		<Logger name="com.james.usinglog.MybatisInterceptor" level="warn" additivity="false">
            <AppenderRef ref="MyFile"/>
        Logger>
1
2
3

RollingFile 的 pattern 有两重含义

1. 确认文件文件名格式，包括路径名
2. 结合 TimeBasedTriggeringPolicy 使用时候, 形如 %d{yyyy-MM-dd_HH-mm} 的模式告知了最小的计量单位是分钟
   • 
     一个文件至多保持5分钟的日志 (JVM一直在运行)
     • 35分钟运行了一次测试用例，36分钟运行了一次测试用例。如果运行完测试用例JVM都退出了，会生成两份日志文件。

<Configuration status="trace">
    <Appenders>
        <RollingFile name="MyFile" filePattern="logs/$${date:yyyy-MM}/app-[%d{yyyy-MM-dd_HH-mm}].log">
            <PatternLayout>
                <Pattern>
                    [%d{MM-dd HH:mm:ss}]-[%p][%tid][%logger{0}:%line]  %m%n
                Pattern>
            PatternLayout>
            <Policies>
                <TimeBasedTriggeringPolicy interval="5"/>
                <SizeBasedTriggeringPolicy size="250 MB"/>
            Policies>
        RollingFile>
    Appenders>
    <Loggers>
        <Logger name="com.james" level="debug" additivity="false">
            <AppenderRef ref="MyFile"/>
        Logger>
        <Logger name="com.james.usinglog.MybatisInterceptor" level="warn" additivity="false">
            <AppenderRef ref="MyFile"/>
        Logger>
        <Root level="info">
            <AppenderRef ref="MyFile"/>
        Root>
    Loggers>
Configuration>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27

后记

本地开发环境的日志配置很灵活，按自己的需求来，好方便排除问题即可。本文积累了下MyBatis完整日志打印的配置和用法和RollingFile 的表达式语义。