Mybatis的parameterType造成线程阻塞问题分析

京东物流钟凯2023年07月28日约 9 分钟

Tech
导读
使用 Mybatis 时，随意配置参数类型竟会在高并发下造成性能问题？本文主要通过源码和对照实验分析 Mybatis 的 parameterType、resultType 参数的不当使用造成线程阻塞的原因。

前言

在今年的敏捷团队建设中，我通过Suite执行器实现了一键自动化单元测试。Juint除了Suite执行器还有哪些执行器呢？由此我的Runner探索之旅开始了！

最近在新发布某个项目上线时，每次重启都会收到机器的 CPU 使用率告警，查看对应监控，持续时长达5分钟，对于服务重启有很大风险。而该项目有非常多 Consumer 消费，服务启动后会有大量线程去拉取消息处理逻辑，通过多次 Jstack 输出线程快照发现有很多 BLOCKED 状态线程，此文主要记录分析 BLOCKED 原因。

分析过程

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目标页面展示到屏幕。

2.1 初步分析

"consumer_order_status_jmq1714_1684822992337" #3125 daemon prio=5 os_prio=0 tid=0x00007fd9eca34000 nid=0x1ca4f waiting for monitor entry [0x00007fd1f33b5000]   java.lang.Thread.State: BLOCKED (on object monitor)    at java.util.concurrent.ConcurrentHashMap.putVal(ConcurrentHashMap.java:1027)    - waiting to lock <0x000000056e822bc8> (a java.util.concurrent.ConcurrentHashMap$Node)    at java.util.concurrent.ConcurrentHashMap.put(ConcurrentHashMap.java:1006)    at org.apache.ibatis.type.TypeHandlerRegistry.getJdbcHandlerMap(TypeHandlerRegistry.java:234)    at org.apache.ibatis.type.TypeHandlerRegistry.getTypeHandler(TypeHandlerRegistry.java:200)    at org.apache.ibatis.type.TypeHandlerRegistry.getTypeHandler(TypeHandlerRegistry.java:191)    at org.apache.ibatis.mapping.ParameterMapping$Builder.resolveTypeHandler(ParameterMapping.java:128)    at org.apache.ibatis.mapping.ParameterMapping$Builder.build(ParameterMapping.java:103)    at org.apache.ibatis.builder.SqlSourceBuilder$ParameterMappingTokenHandler.buildParameterMapping(SqlSourceBuilder.java:123)    at org.apache.ibatis.builder.SqlSourceBuilder$ParameterMappingTokenHandler.handleToken(SqlSourceBuilder.java:67)    at org.apache.ibatis.parsing.GenericTokenParser.parse(GenericTokenParser.java:78)    at org.apache.ibatis.builder.SqlSourceBuilder.parse(SqlSourceBuilder.java:45)    at org.apache.ibatis.scripting.xmltags.DynamicSqlSource.getBoundSql(DynamicSqlSource.java:44)    at org.apache.ibatis.mapping.MappedStatement.getBoundSql(MappedStatement.java:292)    at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:83)  at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)  at com.sun.proxy.$Proxy232.query(Unknown Source)  at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)  at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)  at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)  at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source)  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)  at java.lang.reflect.Method.invoke(Method.java:498)  at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)  at com.sun.proxy.$Proxy124.selectOne(Unknown Source)  at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)  at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)  at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)        ......

通过对服务连续间隔 1 分钟使用 Jstack 抓取线程快照，发现存在部分线程是 BLOCKED 状态，通过堆栈可以看出，当前线程阻塞在 ConcurrentHashMap.putVal，而 putVal 方法内部使用了 synchronized 导致当前线程被 BLOCKED，而上一级是 Mybaits 的 TypeHandlerRegistry，TypeHandlerRegistry 的作用是记录 Java 类型与 JDBC 类型的相互映射关系，例如 java.lang.String 可以映射 JdbcType.CHAR、JdbcType.VARCHAR 等，更上一级是 Mybaits 的 ParameterMapping，而 ParameterMapping 的作用是记录请求参数的信息，包括 Java 类型、JDBC 类型，以及两种类型转换的操作类 TypeHandler。通过以上信息可以初步定位为在并发情况下 Mybaits 解析某些参数导致大量线程被阻塞，还需继续往下分析。

可以先回想下 Mybatis 启动加载时的大致流程，查看下流程中哪些地方会操作 TypeHandler，会使用 ConcurrentHashMap.putVal 进行缓存操作？

图1.Mybatis 启动流程示意

在 Mybatis 启动流程中，大致分为以下几步：

1、XMLConfigBuilder#parseConfiguration() 读取本地XML文件

2、XMLMapperBuilder#configurationElement() 解析XML文件中的 select|insert|update|delete 标签

3、XMLMapperBuilder#parseStatementNode() 开始解析单条 SQL，包括请求参数、返回参数、替换占位符等

4、SqlSourceBuilder 组合单条 SQL 的基本信息

5、SqlSourceBuilder#buildParameterMapping() 解析请求参数

6、ParameterMapping#getJdbcHandlerMap() 解析 Java 与 JDBC 类型，并把映射结果放入缓存

而在第6步时候（图1中标色），会去获取 Java 对象类型与 JDBC 类型的映射关系，并把已经处理过的映射关系 TypeHandler 存入本地缓存中。但是堆栈信息显示，还是触发了 TypeHandler 入缓存的操作，也就是某个 paramType 并没有命中缓存，而是在 SQL 查询的时候实时解析 paramType，在高并发情况下造成了线程阻塞情况。下面继续分析下 sql xml 的配置：

<select id="listxxxByMap" parameterType="java.util.Map" resultMap="BaseResultMap">        select        <include refid="Base_Column_List"/>        from xxxxx        where business_id = #{businessId,jdbcType=VARCHAR}        and template_id = #{templateId,jdbcType=INTEGER}    </select>

代码请求：

Map<String, Object> params = new HashMap<>();params.put("businessId", "11111");params.put("templateId", "11111");List<TrackingInfo> result = trackingInfoMapper.listxxxByMap(params);

初步看没发现问题，但是在入 TypeHandler 缓存时 debug 下，分析下哪种类型在缓存中缺失？

图2. debug 信息示意

从 debug 信息中可以看出，TypeHandler 缓存中存在的是 interface java.util.Map，而 SQL 执行时传入的是 class java.util.HashMap，导致并没有命中缓存。那修改下 xml 文件为 parameterType="java.util.HashMap" 是不是就解决了？

很遗憾，部署后仍然存在问题。

2.2 进一步分析

为了进一步分析，引入了对照组，而对照组的 paramType 为具体 JavaBean。

<select id="listResultMap" parameterType="com.jdwl.xxx.domain.TrackingInfo" resultMap="BaseResultMap">        select        <include refid="Base_Column_List"/>        from xxxx        where business_id = #{businessId,jdbcType=VARCHAR}        and template_id = #{templateId,jdbcType=INTEGER}    </select>

对照组代码请求：

TrackingInfo record = new TrackingInfo();record.setBusinessId("11111");record.setTemplateId(11111);List<TrackingInfo> result = trackingInfoMapper.listResultMap(record);

在装载参数的 Handler 类 org.apache.ibatis.scripting.defaults.DefaultParameterHandler#setParameters 处进行 debug 分析。

2.2.1 对照组为 listResultMap(paramType=JavaBean)

图3.对照组debug分析示意

两个参数的解析类型分别为 StringTypeHandler（红框中灰色的字）与 IntegerTypeHandler（红框中灰色的字），已经是 Mybatis 提供的 TypeHandler，并没有再进行类型的二次解析。说明 JavaBean 中的 businessId、templateId 字段已经在启动时候被预解析了。

2.2.2 实验组为listxxxByMap(paramType=Map)

图4、5.实验组debug分析示意

两个参数的解析都是 UnknownTypeHandler（红框中灰色的字），而在 UnknownTypeHandler 中会再次调用 resolveTypeHandler() 方法，对参数进行类型的二次解析。可以理解为 Map 里的属性不是固定类型，只能在执行 SQL 时候再解析一次。

最后修改为 paramType=JavaBean 部署测试环境再抓包，并未发现 TypeHandlerRegistry 相关的线程阻塞。

引申思考

既然 paramType 传值会出现阻塞问题，那 resultType 与 resultMap 是不是有相同问题呢？继续分为两个组实验：

1、对照组（resultMap=BaseResultMap）

<resultMap id="BaseResultMap" type="com.jdwl.tracking.domain.TrackingInfo">        <id column="id" property="id" jdbcType="BIGINT"/>        <result column="template_id" property="templateId" jdbcType="INTEGER"/>        <result column="business_id" property="businessId" jdbcType="VARCHAR"/>        <result column="is_delete" property="isDelete" jdbcType="TINYINT"/>        <result column="create_time" property="createTime" jdbcType="TIMESTAMP"/>        <result column="update_time" property="updateTime" jdbcType="TIMESTAMP"/>        <result column="ts" property="ts" jdbcType="TIMESTAMP"/>    </resultMap>
<select id="listResultMap" parameterType="com.jdwl.tracking.domain.TrackingInfo" resultMap="BaseResultMap">        select        <include refid="Base_Column_List"/>        from tracking_info        where business_id = #{businessId,jdbcType=VARCHAR}        and template_id = #{templateId,jdbcType=INTEGER}    </select>

对照组代码请求：

TrackingInfo record = new TrackingInfo();record.setBusinessId("11111");record.setTemplateId(11111);List<TrackingInfo> result1 = trackingInfoMapper.listResultMap(record);

2、实验组（resultType=JavaBean）

<select id="listResultType" parameterType="com.jdwl.tracking.domain.TrackingInfo" resultType="com.jdwl.tracking.domain.TrackingInfo">        select        <include refid="Base_Column_List"/>        from tracking_info        where business_id = #{businessId,jdbcType=VARCHAR}        and template_id = #{templateId,jdbcType=INTEGER}    </select>

实验组代码请求：

TrackingInfo record = new TrackingInfo();record.setBusinessId("11111");record.setTemplateId(11111);List<TrackingInfo> result2 = trackingInfoMapper.listResultType(record);

再对返回结果 Handler 处理类 org.apache.ibatis.executor.resultset.DefaultResultSetHandler#createAutomaticMappings() 进行 debug 分析。

1、对照组（resultMap=BaseResultMap）

图6、7.对照组debug分析示意

List<String> unmappedColumnNames 长度为0，表示所有字段都命中了<resultMap>标签配置，符合预期。

2、实验组（resultType=JavaBean）

图8、9.实验组debug分析示意

List<String> unmappedColumnNames 长度为11，表示所有字段都在<resultMap>标签配置中未找到。这是因为 SQL 执行后的 resultMap 对应的 id 并不等于<resultMap>标签的 id，所以这些字段被标识为未解析，又会执行 TypeHandlerRegistry 的类型映射逻辑，引发并发时线程阻塞问题。

总结

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目

1、在使用 paramType 时，xml 配置的类型需要与 Java 代码中传入的一致，使用 Mybatis 预加载时的类型缓存。

2、在使用 paramType 时，避免使用 java.util.HashMap 类型，避免 SQL 执行时解析 TypeHandler。

3、在接受返回值时，使用 resultMap，提前映射返回值，减少 TypeHandler 解析。

后续

现在 Mybatis 社区已经优化了 TypeHandler 入缓存的逻辑，可以解决重复计算 TypeHandler 问题，一定程度上缓解了以上问题。但是 Mybatis 修复最低版本为 3.5.8，依赖 spring5.x，而示例项目使用的 Mybatis3.4.4，spring4.x，直接升级会存在一定风险，不过在不升级的情况下，按照总结规范使用也可以降低阻塞风险。

TypeHandler 相关 issue：https://github.com/mybatis/mybatis-3/pull/2300/commits/8690d60cad1f397102859104fee1f6e6056a0593