写点什么

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

  • 2023-06-08
    北京
  • 本文字数:4902 字

    阅读完需:约 16 分钟

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

一、前言

最近在新发布某个项目上线时,每次重启都会收到机器的 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 <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 进行缓存操作?



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



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


两个参数的解析类型分别为 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)


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




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


2、实验组(resultType=JavaBean)




List<String> unmappedColumnNames 长度为 11,表示所有字段都在 <resultMap> 标签配置中未找到。这是因为 SQL 执行后的 resultMap 对应的 id 并不等于<resultMap>标签的 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


作者:京东物流 张凯

来源:京东云开发者社区

发布于: 刚刚阅读数: 3
用户头像

拥抱技术,与开发者携手创造未来! 2018-11-20 加入

我们将持续为人工智能、大数据、云计算、物联网等相关领域的开发者,提供技术干货、行业技术内容、技术落地实践等文章内容。京东云开发者社区官方网站【https://developer.jdcloud.com/】,欢迎大家来玩

评论

发布
暂无评论
Mybatis的parameterType造成线程阻塞问题分析 | 京东云技术团队_mybatis_京东科技开发者_InfoQ写作社区