当前位置: 首页 > 图灵资讯 > 技术篇> Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队

来源:图灵教育
时间:2023-06-11 09:10:09

一、前言

最近,当新发布的项目上线时,每次重启都会收到机器 CPU 使用率报警,检查相应的监控,持续时间长达 5 分钟,服务重启的风险很大。而且这个项目很多 Consumer 通过多次消费,服务启动后会有大量的线程拉取消息处理逻辑 Jstack 发现输出线程快照有很多 BLOCKED 本文主要记录分析状态线程 BLOCKED 原因。

二、分析过程2.1、初步分析
"consumer_order_status_jmq1714_168429237 #3125 daemon prio=5 os_prio=0 tid=00007fd9eca340000 nid=0x1ca4f waiting for monitor entry [0x00007fd1f3b5000]   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.Generatedmethodacesor16.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的parameterType造成线程阻塞问题分析 | 京东云技术团队_CPU

在 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 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 下面,分析哪种类型的缓存缺失?

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_CPU_02

从 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)

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_java_03

两个参数的分析类型是 StringTypeHandler(红框中的灰色字)与 IntegerTypeHandler(红框中的灰色字),已经是了 Mybatis 提供的 TypeHandler,类型的二次分析没有进行。说明 JavaBean 中的 businessId、templateId 启动时已预先分析了字段。

2.2.2、listxxbyMaplist实验组(paramType=Map)

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_线程阻塞_04

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_线程阻塞_05

两个参数的分析都是 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)

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_java_06

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_Mybatis_07

List 符合预期的标签配置。

2、实验组(resultType=JavaBean)

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_线程阻塞_08

Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_CPU_09

List标签 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.spring4.4.x,直接升级会有一定的风险,所以在不升级的情况下,按照总结规范使用也可以降低阻塞风险。

TypeHandler 相关issue:<https://github.com/mybatis/mybatis-3/pull/2300/commits/8690d60cad1f397028904fe6056a>

作者:京东物流 钟凯

来源:京东云开发者社区: