处理性能过慢的问题排查与优化一、问题现象某业务场景设备发送DurableOutBindAllRequest消息后DurableOutBindAllRequestProcessor.postProcessing()执行缓慢主要卡在两个地方1.coldPlateBindApi.deleteAll(...)逐条删除慢两条删除之间间隔约 2.5 秒15:22:58.741 delete [ColdPlateBind(...2660030335/M03)] ← 第 1 条删完 15:23:01.189 doWork PK[ColdPlateBindPk(...2660031491/M03)] ← 第 2 条才开始隔了 ~2.5s 15:23:01.191 delete [ColdPlateBind(...2660031491/M03)]另一份日志里deleteAll整体OUT elapse[5551]5.5 秒删 2 条。2.generateEapBindRealtionBySql(...)里的update慢assingCarrier内部调用的名称生成update前有约 8 秒空档13:11:10.947 IN : invoke[EventApiImpl.update] args[[NameRuleSerialDef(...preFixP10)]] 13:11:18.725 doWork PK[NameRuleSerialDefPk(...preFixP10)] ← 隔了 ~8s 才开始 doWork 13:11:18.727 update [NameRuleSerialDef(...preFixP10)]二、根因分析2.1deleteAll不是批量删除而是逐条循环ColdPlateBindApiImpl没有自己的实现直接继承 Core JAR 里的EventApiImpl。反编译EventApiImpl.deleteAll(List)可见它只是把 List 拿出来一条条循环调用delete(D)// EventApiImpl.deleteAll 反编译for(EventDatad:list){delete(d);// 每条都走完整流程}单条delete(D)每条要执行getClaims();em.getMetamodel().entityPersister(...).getEntityTuplizer().getIdentifier(...);repo.findById(id);// 一次 DB 查询event(id,taskInfo,postAction);// doWork / postAction / addHistory 整套 EventTask 流程repo.delete(entity);日志里的doWork → postAction → addHistory → delete正是这一条的处理过程。2.2 真正的瓶颈大事务导致的 Hibernate autoflushpostProcessing()整体包在一个PROPAGATION_REQUIRES_NEW的大事务里从getTransaction(def)到commit(status)之间的所有操作trackOut、mergeLot、qrCodeRelation/product 的 event、deleteAll、assingCarrier全部跑在同一个事务、同一个 Hibernate Session持久化上下文里。问题链路事务内没有中途 flush/clear实体只增不减地累积在持久化上下文里全是 dirty 状态。delete/update/find这类操作执行前Hibernate 的FlushMode.AUTO会对整个膨胀的 Session做 dirty check flush。Session 越大每次 autoflush 越重。deleteAll循环每一圈都会重复触发这个重 flush → 两条删除之间隔了 2.5 秒generateEapBindRealtionBySql的update前同理隔了 8 秒。结论慢不是 SQL 本身慢而是每一步操作前的 autoflush 在反复扫描肥大的持久化上下文。这和事务传播类型REQUIRES_NEW无关换成REQUIRED也一样根因是大事务 → 大 Session → 每次 autoflush 都重。2.3 补充一处冗余查询postProcessing()开头已用coldPlateBindApi.findAllWithEquals(query)查出待删实体但delete(D)内部又对每条重新findById查一遍查询重复本次未针对该点改动因其耗时占比小。三、解决方案保留历史记录ColdPlateBindHist的前提下逐条 event 流程不能省但可以在进入deleteAll/assingCarrier之前主动清空持久化上下文让后续每步的 autoflush 面对一个干净、轻量的 Session。核心两行entityManager.flush();// 先把前面累积的 dirty 变更一次性写库该写的还是要写不亏entityManager.clear();// 再清空持久化上下文后续操作的 autoflush 不必再扫这堆实体放在if外面、deleteAll和assingCarrier之前保证无论coldPlateBindResult是否有数据assingCarrier里的update都能受益。为什么有效flush()把前面所有 dirty 实体一次性写库。这次写省不掉commit 时也要写但集中做一次。clear()把这些实体从 Session detach。之后deleteAll每条findById、以及generateEapBindRealtionBySql的update触发 autoflush 时面对的是一个空 Sessiondirty check 立刻返回。每条delete的addHistory照常执行历史记录不受影响。关于事务与顺序的注意点顺序必须 flush 在前、clear 在后。clear()会丢弃尚未 flush 的变更先 flush 保证前面 trackOut/merge/event 的改动已落到数据库再 clear 只是 detach不会丢数据。对 commit 无负面影响。flush()只改变何时发 SQL不改变何时提交异常时rollback(status)仍会把 flush 出去的 SQL 一起回滚原子性不变。assingCarrier保持在 commit 之前的 try 块内。曾尝试把它移到 commit 之后会脱离事务、异常时无法回滚已否决并还原。clear()会 detach 所有实体含modingBodyLotList。改动后assingCarrier只读getLotName()/getFactoryName()等已加载字段内部用new LotPk(...)/new DurablePk(...)重新按主键操作不依赖托管态安全。
Session处理性能过慢的问题排查与优化
处理性能过慢的问题排查与优化一、问题现象某业务场景设备发送DurableOutBindAllRequest消息后DurableOutBindAllRequestProcessor.postProcessing()执行缓慢主要卡在两个地方1.coldPlateBindApi.deleteAll(...)逐条删除慢两条删除之间间隔约 2.5 秒15:22:58.741 delete [ColdPlateBind(...2660030335/M03)] ← 第 1 条删完 15:23:01.189 doWork PK[ColdPlateBindPk(...2660031491/M03)] ← 第 2 条才开始隔了 ~2.5s 15:23:01.191 delete [ColdPlateBind(...2660031491/M03)]另一份日志里deleteAll整体OUT elapse[5551]5.5 秒删 2 条。2.generateEapBindRealtionBySql(...)里的update慢assingCarrier内部调用的名称生成update前有约 8 秒空档13:11:10.947 IN : invoke[EventApiImpl.update] args[[NameRuleSerialDef(...preFixP10)]] 13:11:18.725 doWork PK[NameRuleSerialDefPk(...preFixP10)] ← 隔了 ~8s 才开始 doWork 13:11:18.727 update [NameRuleSerialDef(...preFixP10)]二、根因分析2.1deleteAll不是批量删除而是逐条循环ColdPlateBindApiImpl没有自己的实现直接继承 Core JAR 里的EventApiImpl。反编译EventApiImpl.deleteAll(List)可见它只是把 List 拿出来一条条循环调用delete(D)// EventApiImpl.deleteAll 反编译for(EventDatad:list){delete(d);// 每条都走完整流程}单条delete(D)每条要执行getClaims();em.getMetamodel().entityPersister(...).getEntityTuplizer().getIdentifier(...);repo.findById(id);// 一次 DB 查询event(id,taskInfo,postAction);// doWork / postAction / addHistory 整套 EventTask 流程repo.delete(entity);日志里的doWork → postAction → addHistory → delete正是这一条的处理过程。2.2 真正的瓶颈大事务导致的 Hibernate autoflushpostProcessing()整体包在一个PROPAGATION_REQUIRES_NEW的大事务里从getTransaction(def)到commit(status)之间的所有操作trackOut、mergeLot、qrCodeRelation/product 的 event、deleteAll、assingCarrier全部跑在同一个事务、同一个 Hibernate Session持久化上下文里。问题链路事务内没有中途 flush/clear实体只增不减地累积在持久化上下文里全是 dirty 状态。delete/update/find这类操作执行前Hibernate 的FlushMode.AUTO会对整个膨胀的 Session做 dirty check flush。Session 越大每次 autoflush 越重。deleteAll循环每一圈都会重复触发这个重 flush → 两条删除之间隔了 2.5 秒generateEapBindRealtionBySql的update前同理隔了 8 秒。结论慢不是 SQL 本身慢而是每一步操作前的 autoflush 在反复扫描肥大的持久化上下文。这和事务传播类型REQUIRES_NEW无关换成REQUIRED也一样根因是大事务 → 大 Session → 每次 autoflush 都重。2.3 补充一处冗余查询postProcessing()开头已用coldPlateBindApi.findAllWithEquals(query)查出待删实体但delete(D)内部又对每条重新findById查一遍查询重复本次未针对该点改动因其耗时占比小。三、解决方案保留历史记录ColdPlateBindHist的前提下逐条 event 流程不能省但可以在进入deleteAll/assingCarrier之前主动清空持久化上下文让后续每步的 autoflush 面对一个干净、轻量的 Session。核心两行entityManager.flush();// 先把前面累积的 dirty 变更一次性写库该写的还是要写不亏entityManager.clear();// 再清空持久化上下文后续操作的 autoflush 不必再扫这堆实体放在if外面、deleteAll和assingCarrier之前保证无论coldPlateBindResult是否有数据assingCarrier里的update都能受益。为什么有效flush()把前面所有 dirty 实体一次性写库。这次写省不掉commit 时也要写但集中做一次。clear()把这些实体从 Session detach。之后deleteAll每条findById、以及generateEapBindRealtionBySql的update触发 autoflush 时面对的是一个空 Sessiondirty check 立刻返回。每条delete的addHistory照常执行历史记录不受影响。关于事务与顺序的注意点顺序必须 flush 在前、clear 在后。clear()会丢弃尚未 flush 的变更先 flush 保证前面 trackOut/merge/event 的改动已落到数据库再 clear 只是 detach不会丢数据。对 commit 无负面影响。flush()只改变何时发 SQL不改变何时提交异常时rollback(status)仍会把 flush 出去的 SQL 一起回滚原子性不变。assingCarrier保持在 commit 之前的 try 块内。曾尝试把它移到 commit 之后会脱离事务、异常时无法回滚已否决并还原。clear()会 detach 所有实体含modingBodyLotList。改动后assingCarrier只读getLotName()/getFactoryName()等已加载字段内部用new LotPk(...)/new DurablePk(...)重新按主键操作不依赖托管态安全。