一、前言
最近在新发布某个项目上线时，每次重启都会收到机器的 CPU 使用率告警，查看对应监控，持续时长达 5 分钟，对于服务重启有很大风险。而该项目有非常多 Consumer 消费，服务启动后会有大量线程去拉取消息处理逻辑，通过多次 Jstack 输出线程快照发现有很多 BLOCKED 状态线程，此文主要记录分析 BLOCKED 原因。
二、分析过程
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 (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 进行缓存操作？
在 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 步时候（图中标色），会去获取 Java 对象类型与 JDBC 类型的映射关系，并把已经处理过的映射关系 TypeHandler 存入本地缓存中。但是堆栈信息显示，还是触发了 TypeHandler 入缓存的操作，也就是某个 paramType 并没有命中缓存，而是在 SQL 查询的时候实时解析 paramType，在高并发情况下造成了线程阻塞情况。下面继续分析下 sql xml 的配置：
select
from xxxxx
where business_id = #{businessId,jdbcType=VARCHAR}
and template_id = #{templateId,jdbcType=INTEGER}
代码请求：
Map params = new HashMap();
params.put("businessId", "11111");
params.put("templateId", "11111");
List result = trackingInfoMapper.listxxxByMap(params);
初步看没发现问题，但是我们在入 TypeHandler 缓存时 debug 下，分析下哪种类型在缓存中缺失？
从 debug 信息中可以看出，TypeHandler 缓存中存在的是 interface java.util.Map，而 SQL 执行时传入的是 class java.util.HashMap，导致并没有命中缓存。那我们修改下 xml 文件为 parameterType=”java.util.HashMap” 是不是就解决了？
很遗憾，部署后仍然存在问题。
2.2、进一步分析
为了进一步分析，引入了对照组，而对照组的 paramType 为具体 JavaBean。
select
from xxxx
where business_id = #{businessId,jdbcType=VARCHAR}
and template_id = #{templateId,jdbcType=INTEGER}
对照组代码请求
TrackingInfo record = new TrackingInfo();
record.setBusinessId("11111");
record.setTemplateId(11111);
List result = trackingInfoMapper.listResultMap(record);
在装载参数的 Handler 类 org.apache.ibatis.scripting.defaults.DefaultParameterHandler#setParameters 处进行 debug 分析。
2.2.1、对照组为 listResultMap（paramType=JavaBean）
两个参数的解析类型分别为 StringTypeHandler（红框中灰色的字）与 IntegerTypeHandler（红框中灰色的字），已经是 Mybatis 提供的 TypeHandler，并没有再进行类型的二次解析。说明 JavaBean 中的 businessId、templateId 字段已经在启动时候被预解析了。
2.2.2、实验组为listxxxByMap（paramType=Map）
两个参数的解析都是 UnknownTypeHandler（红框中灰色的字），而在 UnknownTypeHandler 中会再次调用 resolveTypeHandler() 方法，对参数进行类型的二次解析。可以理解为 Map 里的属性不是固定类型，只能在执行 SQL 时候再解析一次。
最后修改为 paramType=JavaBean 部署测试环境再抓包，并未发现 TypeHandlerRegistry 相关的线程阻塞。
三、引申思考
既然 paramType 传值会出现阻塞问题，那 resultType 与 resultMap 是不是有相同问题呢？继续分为两个实验组：
1、对照组（resultMap=BaseResultMap）
select
from tracking_info
where business_id = #{businessId,jdbcType=VARCHAR}
and template_id = #{templateId,jdbcType=INTEGER}
对照组代码请求：
TrackingInfo record = new TrackingInfo();
record.setBusinessId("11111");
record.setTemplateId(11111);
List result1 = trackingInfoMapper.listResultMap(record);
2、实验组（resultType=JavaBean）
select
from tracking_info
where business_id = #{businessId,jdbcType=VARCHAR}
and template_id = #{templateId,jdbcType=INTEGER}
实验组代码请求：
TrackingInfo record = new TrackingInfo();
record.setBusinessId("11111");
record.setTemplateId(11111);
List result2 = trackingInfoMapper.listResultType(record);
在对返回结果 Handler 处理类 org.apache.ibatis.executor.resultset.DefaultResultSetHandler#createAutomaticMappings() 进行 debug 分析。
1、对照组（resultMap=BaseResultMap）
List unmappedColumnNames 长度为 0，表示所有字段都命中了 标签配置，符合预期。
2、实验组（resultType=JavaBean）
List unmappedColumnNames 长度为 11，表示所有字段都在 标签配置中未找到。这是因为 SQL 执行后的 resultMap 对应的 id 并不等于标签的 id，所以这些字段被标识为未解析，又会执行 TypeHandlerRegistry 的类型映射逻辑，引发并发时线程阻塞问题。
四、总结
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
作者：京东物流 钟凯
来源：京东云开发者社区
服务器托管，北京服务器托管，服务器租用 http://www.fwqtg.net
