Mybatis的sql语句执行异常后打印到日志

最近做的一个运维提的需求。希望插入和更新的sql语句时，如果执行失败，能打印到一个专门的日志文件里。他可以用来恢复数据库里的数据。

在网上调研了下可以实现这个功能的方案：
1、可以通过Mybatis拦截器可以获取到执行的sql语句
2、由于我们的数据库都是异步写的，所以会存在多线程的问题，如果用一个变量存，可能会出现这条sql还没读出来就被别的线程的sql语句覆盖的问题，线程不安全。所以考虑用ThreadLocal存Mybatis拦截器的sql语句。
3、在异常的catch代码段里，将ThreadLocal存的sql语句取出，打印到单独的日志文件里。

具体实现代码

Mybatis拦截器（只拦截插入更新操作，拼接sql后塞入ThreadLocal）：

/**
 * Mybatis拦截器，用于拼接sql语句
 *
 * @author lightonyang
 * @date 2022/10/27
 */
@Intercepts({
        @Signature(type = Executor.class, method = "update", args = {MappedStatement.class,
                Object.class}),
})
public class MybatisInterceptor implements Interceptor {
    // 如果参数是String，则添加单引号， 如果是日期，则转换为时间格式器并加单引号； 对参数是null和不是null的情况作了处理
    private static String getParameterValue(Object obj) {
        String value = null;
        if (obj instanceof String) {
            value = "'" + obj.toString() + "'";
        } 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 =  "null" ;
            }
        }
        return value;
    }

    // 进行？的替换
    public static String showSql(Configuration configuration, BoundSql boundSql) {
        // 获取参数
        Object parameterObject = boundSql.getParameterObject();
        List<ParameterMapping> parameterMappings = boundSql.getParameterMappings();
        // sql语句中多个空格都用一个空格代替
        String sql = boundSql.getSql().replaceAll("[\\s]+", " ");
        if (CollectionUtils.isNotEmpty(parameterMappings) && parameterObject != null) {
            // 获取类型处理器注册器，类型处理器的功能是进行java类型和数据库类型的转换
            TypeHandlerRegistry typeHandlerRegistry = configuration.getTypeHandlerRegistry();
            // 如果根据parameterObject.getClass(）可以找到对应的类型，则替换
            if (typeHandlerRegistry.hasTypeHandler(parameterObject.getClass())) {
                sql = sql.replaceFirst("\\?",
                        Matcher.quoteReplacement(getParameterValue(parameterObject)));
            } else {
                // MetaObject主要是封装了originalObject对象，提供了get和set的方法用于获取和设置originalObject的属性值,主要支持对JavaBean、Collection、Map三种类型对象的操作
                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("\\?",
                                Matcher.quoteReplacement(getParameterValue(obj)));
                    } else if (boundSql.hasAdditionalParameter(propertyName)) {
                        // 该分支是动态sql
                        Object obj = boundSql.getAdditionalParameter(propertyName);
                        sql = sql.replaceFirst("\\?",
                                Matcher.quoteReplacement(getParameterValue(obj)));
                    } else {
                        // 打印出缺失，提醒该参数缺失并防止错位
                        sql = sql.replaceFirst("\\?", "缺失");
                    }
                }
            }
        }
        return sql;
    }

    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        try {
            // 获取xml中的一个select/update/insert/delete节点，是一条SQL语句
            MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0];
            Object parameter = null;
            // 获取参数，if语句成立，表示sql语句有参数，参数格式是map形式
            if (invocation.getArgs().length > 1) {
                parameter = invocation.getArgs()[1];
                System.out.println("parameter = " + parameter);
            }
            String sqlId = mappedStatement.getId(); // 获取到节点的id,即sql语句的id
            System.out.println("sqlId = " + sqlId);
            BoundSql boundSql = mappedStatement.getBoundSql(parameter); // BoundSql就是封装myBatis最终产生的sql类
            Configuration configuration = mappedStatement.getConfiguration(); // 获取节点的配置
            String sql = showSql(configuration, boundSql); // 获取到最终的sql语句
            TheadLocalUtil.instance().sql(sql);
            System.out.println("sql = " + sql);
        } catch (Exception e) {
            e.printStackTrace();
        }
        // 执行完上面的任务后，不改变原有的sql执行过程
        return invocation.proceed();
    }

}
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

将Mybatis拦截器加入配置：

@Configuration
public class SqlMonitorConfiguration {

    @Autowired
    SqlSessionFactory sqlSessionFactory;

    @Bean
    @DependsOn("sqlSessionFactory")
    public MybatisInterceptor mybatisInterceptor() {
        MybatisInterceptor mybatisInterceptor = new MybatisInterceptor();
        sqlSessionFactory.getConfiguration().addInterceptor(mybatisInterceptor);
        return mybatisInterceptor;
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14

ThreadLocalUtil:

/**
 * 由于运维需求，数据库异常后输出sql语句，引入TheadLocal
 * 用于异步多线程写数据库时，存sql语句，保持线程安全
 * 

 * 用完要记得finally里reset，防止内存泄漏
 *
 * @author lightonyang
 * @date 2022/10/31
 */
public class TheadLocalUtil {

    private static final ThreadLocal<TheadLocalUtil> LOCAL = ThreadLocal.withInitial(TheadLocalUtil::new);

    private String sql;

    private TheadLocalUtil() {
    }

    public static TheadLocalUtil instance() {
        return LOCAL.get();
    }

    public TheadLocalUtil reset() {
        sql = null;
        LOCAL.remove();
        return this;
    }

    /*用于链式添加*/
    public TheadLocalUtil sql(String sql) {
        this.sql = sql;
        return this;
    }

    public String getSql() {
        return sql;
    }

    public void setSql(String sql) {
        this.sql = sql;
    }
}

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

日志配置（将异常日志打印到单独的日志文件mysqlfail.log里）：

<Appenders>
		<RollingFile name="mysqlFailFixedTimeFileAppender"
					 fileName="${sys:mumble.log.home}/idap-idasc-mysqlfail.log"
					 filePattern="${sys:mumble.log.home}/idap-idasc-mysqlfail.log.%d{yyyy-MM-dd_HH}-%i.log">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p %c{1}(%F:%L) - %m%n"/>
			<Policies>
				<TimeBasedTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="200 MB"/>
			</Policies>
			<DefaultRolloverStrategy max="24"/>
		</RollingFile>
</Appenders>

<Loggers>
		<AsyncLogger name="mysqlFail" level="info" additivity="false"
					 includeLocation="true">
			<AppenderRef ref="mysqlFailFixedTimeFileAppender"/>
		</AsyncLogger>
</Loggers>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19

日志使用（在操作数据的Impl中catch异常，从ThreadLocal中拿出sql语句打印日志）：

private static final Logger MYSQL_FAIL_LOG = LoggerFactory.getLogger("mysqlFail");

	try{
	···
	}catch{
		MYSQL_FAIL_LOG.info(TheadLocalUtil.instance().getSql(sql););
	}finally{
		TheadLocalUtil.reset();
	}
1
2
3
4
5
6
7
8
9

这种实现方法也经过了测试的压测，没有出现多线程下的sql语句覆盖的问题，也没有出现内存泄漏和性能问题，满足了需求的使用。