前言碎语
最近线上spring batch的一个问题围绕博主近两周时间,甚是扰神。具体现象为,spring batch执行中莫名其妙线程就卡住了,不往下走了。下面会详细描述整个问题的排查过程
环境说明
spring batch分区环境,共6个分片,两台实例,分别6个线程处理,由xxljob任务调度触发日切job,配置由apollo管理。
排查过程
1.xxljob长连接导致
why?因为我们有项目是老项目,任务调度使用的quartz,原来的批处理没啥毛病。
然后修改了dayEndjob的触发执行改为异步,发现问题依旧。
2.定位JpaPagingItemReader的问题
盯着BATCH_STEP_EXECUTION看了很久,发现其他的step_execution都是启动中的状态,其中两个step_execution是读取中,并且和其他step_execution明显区别version版本一直在增加,初步判断有线程一直在修改.但是日志一点动静都没有,如果是线程阻塞了,肯定也不存在线程修改数据库数据。然后在apollo把日志级别调整成DEBUG级别(动态调整线上日志级别),发现输出大量的如下日志信息
java.lang.IllegalStateException: Transaction already active at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:42) at org.springframework.batch.item.database.JpaPagingItemReader.doReadPage(JpaPagingItemReader.java:197) at org.springframework.batch.item.database.AbstractPagingItemReader.doRead(AbstractPagingItemReader.java:108) at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.read(AbstractItemCountingItemStreamItemReader.java:88) at org.springframework.batch.item.support.SynchronizedItemStreamReader.read(SynchronizedItemStreamReader.java:55) at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) at com.sun.proxy.$Proxy126.read(Unknown Source) at org.springframework.batch.core.step.item.SimpleChunkProvider.doRead(SimpleChunkProvider.java:91) at org.springframework.batch.core.step.item.FaultTolerantChunkProvider.read(FaultTolerantChunkProvider.java:87) at org.springframework.batch.core.step.item.SimpleChunkProvider$1.doInIteration(SimpleChunkProvider.java:116) at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:374) at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:215) at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:144) at org.springframework.batch.core.step.item.SimpleChunkProvider.provide(SimpleChunkProvider.java:110) at org.springframework.batch.core.step.item.ChunkOrientedTasklet.execute(ChunkOrientedTasklet.java:69) at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:406) at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:330) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133) at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:272) at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:81) at org.springframework.batch.repeat.support.TaskExecutorRepeatTemplate$ExecutingRunnable.run(TaskExecutorRepeatTemplate.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)3.确定JpaPagingItemReader的问题
因为项目使用了jpa。故而数据读取器用用了JpaPagingItemReader,从异常信息找到JpaPagingItemReader文件后发现,JpaPagingItemReader根据配置的transacted=true,编程式的开启了事务,而提交事务和回滚事务并没有作try,catch处理,而一旦抛出了如上事务异常,因为FaultTolerantChunkProvider 读取数据实现如下
就会进入一个一直抛异常的死循环,至此所有问题都清晰明了了。
解决问题
参照JpaPagingItemReader既有的实现,自定义一个CustomJpaPagingItemReader阅读器,去掉事务部分代码,或者实例化JpaPagingItemReader的时候设置transacted为false。这个参数主要用途我猜测是为了让用户自己选择查询出来的对象是否为entityManager管理的游离态。我们项目用不着,就直接去掉事务部分了。一般如果查询没问题,不会有如上情况,这个bug也是隐藏的深,死循环后info日志级别下没有任何输出,就和线程阻塞似的。解决这个问题后感觉神清气爽啊