生产环境 java.util.concurrent.RejectedExecutionException: event executor terminated 错误分析
?今天運維在執行線上功能時發現服務異常,跟進之后發現Redis出現問題,如下:
[ERROR] [2022-05-26 00:05:01.518] [c.q.d.utils.DataAccessSampleRedisUtil:326][Thread-154] 服務名稱:ivdg-data-access-service--> 查詢緩存數據出錯:Unknown redis exception; nested exception is java.util.concurrent.RejectedExecutionException: event executor terminated org.springframework.data.redis.RedisSystemException: Unknown redis exception; nested exception is java.util.concurrent.RejectedExecutionException: event executor terminatedat org.springframework.data.redis.FallbackExceptionTranslationStrategy.getFallback(FallbackExceptionTranslationStrategy.java:53)at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:43)at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:273)at org.springframework.data.redis.connection.lettuce.LettuceScriptingCommands.convertLettuceAccessException(LettuceScriptingCommands.java:236)at org.springframework.data.redis.connection.lettuce.LettuceScriptingCommands.evalSha(LettuceScriptingCommands.java:195)at org.springframework.data.redis.connection.DefaultedRedisConnection.evalSha(DefaultedRedisConnection.java:1502)at org.springframework.data.redis.connection.DefaultStringRedisConnection.evalSha(DefaultStringRedisConnection.java:1757)at sun.reflect.GeneratedMethodAccessor606.invoke(Unknown Source)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at org.springframework.data.redis.core.CloseSuppressingInvocationHandler.invoke(CloseSuppressingInvocationHandler.java:61)at com.sun.proxy.$Proxy258.evalSha(Unknown Source)at org.springframework.data.redis.core.script.DefaultScriptExecutor.eval(DefaultScriptExecutor.java:77)at org.springframework.data.redis.core.script.DefaultScriptExecutor.lambda$execute$0(DefaultScriptExecutor.java:68)at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:228)at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:188)at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:175)at org.springframework.data.redis.core.script.DefaultScriptExecutor.execute(DefaultScriptExecutor.java:58)at org.springframework.data.redis.core.script.DefaultScriptExecutor.execute(DefaultScriptExecutor.java:52)at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:350)at com.qsdi.dataAccess.utils.DataAccessSampleRedisUtil.lambda$scanData$7(DataAccessSampleRedisUtil.java:324)at java.util.stream.Streams$RangeIntSpliterator.forEachRemaining(Streams.java:110)at java.util.stream.IntPipeline$Head.forEach(IntPipeline.java:559)at com.qsdi.dataAccess.utils.DataAccessSampleRedisUtil.scanData(DataAccessSampleRedisUtil.java:318)at com.qsdi.dataAccess.service.impl.DataSamplingInspectionHourStatisticsServiceImpl.handleHourData(DataSamplingInspectionHourStatisticsServiceImpl.java:69)at com.qsdi.dataAccess.service.impl.DataSamplingInspectionHourStatisticsServiceImpl.statisticsDataByTime(DataSamplingInspectionHourStatisticsServiceImpl.java:58)at com.qsdi.dataAccess.job.HourStatisticsByVehicleJobHandler.execute(HourStatisticsByVehicleJobHandler.java:29)at com.xxl.job.core.thread.JobThread.run(JobThread.java:163) Caused by: java.util.concurrent.RejectedExecutionException: event executor terminatedat io.netty.util.concurrent.SingleThreadEventExecutor.reject(SingleThreadEventExecutor.java:926)at io.netty.util.concurrent.SingleThreadEventExecutor.offerTask(SingleThreadEventExecutor.java:353)at io.netty.util.concurrent.SingleThreadEventExecutor.addTask(SingleThreadEventExecutor.java:346)at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:828)at io.netty.util.concurrent.SingleThreadEventExecutor.execute(SingleThreadEventExecutor.java:818)at io.netty.util.concurrent.AbstractScheduledEventExecutor.schedule(AbstractScheduledEventExecutor.java:261)at io.netty.util.concurrent.AbstractScheduledEventExecutor.schedule(AbstractScheduledEventExecutor.java:177)at io.netty.util.concurrent.AbstractEventExecutorGroup.schedule(AbstractEventExecutorGroup.java:50)at io.netty.util.concurrent.AbstractEventExecutorGroup.schedule(AbstractEventExecutorGroup.java:32)at io.lettuce.core.protocol.CommandExpiryWriter.potentiallyExpire(CommandExpiryWriter.java:168)at io.lettuce.core.protocol.CommandExpiryWriter.write(CommandExpiryWriter.java:115)at io.lettuce.core.RedisChannelHandler.dispatch(RedisChannelHandler.java:195)at io.lettuce.core.StatefulRedisConnectionImpl.dispatch(StatefulRedisConnectionImpl.java:176)at io.lettuce.core.AbstractRedisAsyncCommands.dispatch(AbstractRedisAsyncCommands.java:474)at io.lettuce.core.AbstractRedisAsyncCommands.evalsha(AbstractRedisAsyncCommands.java:512)at sun.reflect.GeneratedMethodAccessor608.invoke(Unknown Source)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at io.lettuce.core.FutureSyncInvocationHandler.handleInvocation(FutureSyncInvocationHandler.java:63)at io.lettuce.core.internal.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:79)at com.sun.proxy.$Proxy254.evalsha(Unknown Source)at org.springframework.data.redis.connection.lettuce.LettuceScriptingCommands.evalSha(LettuceScriptingCommands.java:193)... 23 common frames omitted如上代碼段所示, 再調用redis執行luna腳本查詢時提示異常,具體異常描述是由SingeThreadEventExecutor這個類調用execute方法時出現的異常,源碼如下:
private void execute(Runnable task, boolean immediate) {boolean inEventLoop = inEventLoop();addTask(task);if (!inEventLoop) {startThread();if (isShutdown()) {boolean reject = false;try {if (removeTask(task)) {reject = true;}} catch (UnsupportedOperationException e) {// The task queue does not support removal so the best thing we can do is to just move on and// hope we will be able to pick-up the task before its completely terminated.// In worst case we will log on termination.}if (reject) {reject();}}}if (!addTaskWakesUp && immediate) {wakeup(inEventLoop);}}分析這個方法,大意是將當前寫事件提交到 SingleThreadEventExecutor 任務隊列中。報錯是在 addTask 這個方法:
/*** Add a task to the task queue, or throws a {@link RejectedExecutionException} if this instance was shutdown* before.*/protected void addTask(Runnable task) {ObjectUtil.checkNotNull(task, "task");if (!offerTask(task)) {reject(task);}}這個方法判斷如果沒有插入任務隊列成功就調用 reject (task) 拒絕任務,reject (task) 里面拋出的異常就是我們看到的最外面的異常。于是看一看 offerTask 方法:
final boolean offerTask(Runnable task) {if (isShutdown()) {reject();}return taskQueue.offer(task);}@Overridepublic boolean isShutdown() {return state >= ST_SHUTDOWN;}private static final int ST_NOT_STARTED = 1;private static final int ST_STARTED = 2;private static final int ST_SHUTTING_DOWN = 3;private static final int ST_SHUTDOWN = 4;private static final int ST_TERMINATED = 5;這里可以看出 offerTask 的時候校驗了當前的 SingleThreadEventExecutor 的狀態是否是結束和終止。那么問題來了,是什么導致的 SingleThreadEventExecutor 的狀態為終止的勒,通過前面緣由中日志可以看到 SingleThreadEventExecutor 也打印了堆溢出的錯誤日志,搜索這個日志是哪里打印的,發現:
private void doStartThread() {assert thread == null;executor.execute(new Runnable() {@Overridepublic void run() {thread = Thread.currentThread();if (interrupted) {thread.interrupt();}boolean success = false;updateLastExecutionTime();try {SingleThreadEventExecutor.this.run();success = true;} catch (Throwable t) {logger.warn("Unexpected exception from an event executor: ", t);} finally {for (;;) {int oldState = state;if (oldState >= ST_SHUTTING_DOWN || STATE_UPDATER.compareAndSet(SingleThreadEventExecutor.this, oldState, ST_SHUTTING_DOWN)) {break;}}// Check if confirmShutdown() was called at the end of the loop.if (success && gracefulShutdownStartTime == 0) {if (logger.isErrorEnabled()) {logger.error("Buggy " + EventExecutor.class.getSimpleName() + " implementation; " +SingleThreadEventExecutor.class.getSimpleName() + ".confirmShutdown() must " +"be called before run() implementation terminates.");}}try {// Run all remaining tasks and shutdown hooks. At this point the event loop// is in ST_SHUTTING_DOWN state still accepting tasks which is needed for// graceful shutdown with quietPeriod.for (;;) {if (confirmShutdown()) {break;}}// Now we want to make sure no more tasks can be added from this point. This is// achieved by switching the state. Any new tasks beyond this point will be rejected.for (;;) {int oldState = state;if (oldState >= ST_SHUTDOWN || STATE_UPDATER.compareAndSet(SingleThreadEventExecutor.this, oldState, ST_SHUTDOWN)) {break;}}// We have the final set of tasks in the queue now, no more can be added, run all remaining.// No need to loop here, this is the final pass.confirmShutdown();} finally {try {cleanup();} finally {// Lets remove all FastThreadLocals for the Thread as we are about to terminate and notify// the future. The user may block on the future and once it unblocks the JVM may terminate// and start unloading classes.// See https://github.com/netty/netty/issues/6596.FastThreadLocal.removeAll();STATE_UPDATER.set(SingleThreadEventExecutor.this, ST_TERMINATED);threadLock.countDown();int numUserTasks = drainTasks();if (numUserTasks > 0 && logger.isWarnEnabled()) {logger.warn("An event executor terminated with " +"non-empty task queue (" + numUserTasks + ')');}terminationFuture.setSuccess(null);}}}}});}這個方法,這個方法里面同時在 finally 設置了狀態為 ST_TERMINATED,這個方法大意是啟動 eventloop 真正的線程來輪詢讀寫事件,這個方法將在首次執行 excute 方法的時候被調用,注意這里的 executor 變量是一個線程池,于是查閱資料才認識到,eventloopgroup 下的每個 eventloop 實際上都會引用到一個線程池,這個線程池線程數目與 eventloop 總大小相同,是 fork/join 框架創建的,真正執行輪詢邏輯實際上是這個線程池去提交的。eventloop 的意義實際上只是為了保存任務隊列。真正的去輪詢任務隊列的邏輯是由其代理的線程池去執行的。
這樣也就清楚了,整個事故實際很簡單,就是先由于內存溢出的錯誤導致 eventloop 的狀態為終止,這個終止狀態據我看到的代碼貌似是不可逆的,然后當在調用 chanel.write 的時候提交任務到 eventloop 校驗狀態為終止所以報了拒絕錯誤。
解決這個 bug 的重要途徑是找到內存溢出的原因,這里就不贅述了,因為在網上沒有搜到這個錯的原因,所以跟了一下代碼,在這里做個記錄,后續分析一下到底是哪里有內存溢出問題再貼上解決方案
總結
以上是生活随笔為你收集整理的生产环境 java.util.concurrent.RejectedExecutionException: event executor terminated 错误分析的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: ABBYY FineReader 15
- 下一篇: 内核ppp编制和错误分析