ebean报错：NotifyOfCommit failed. L2 Cache potentially not notified解决办法

我会带着你远行 2022-05-21 13:06 39阅读 0赞

## 问题描述 ##

公司中的一个项目用的ebean框架，有一次在程序的JAR包关闭过程中发现了如下错误

[Thread-2] INFO com.bigdata.datacenter.datasync.server.mysql.MysqlSubjectServer - 扫描程序关闭中...
    [Thread-2] ERROR com.avaje.ebeaninternal.server.transaction.TransactionManager - NotifyOfCommit failed. L2 Cache potentially not notified.
    java.util.concurrent.RejectedExecutionException: Task com.avaje.ebeaninternal.server.transaction.PostCommitProcessing$$Lambda$2/1368391951@6edfcc61 rejected from java.util.concurrent.ThreadPoolExecutor@31956fb3[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 16969]
    	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)
    	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
    	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
    	at com.avaje.ebeaninternal.server.lib.DaemonExecutorService.execute(DaemonExecutorService.java:41)
    	at com.avaje.ebeaninternal.server.core.DefaultBackgroundExecutor.execute(DefaultBackgroundExecutor.java:30)
    	at com.avaje.ebeaninternal.server.transaction.TransactionManager.notifyOfCommit(TransactionManager.java:313)
    	at com.avaje.ebeaninternal.server.transaction.JdbcTransaction.notifyCommit(JdbcTransaction.java:882)
    	at com.avaje.ebeaninternal.server.transaction.JdbcTransaction.flushCommitAndNotify(JdbcTransaction.java:925)
    	at com.avaje.ebeaninternal.server.transaction.JdbcTransaction.commit(JdbcTransaction.java:972)
    	at com.avaje.ebeaninternal.server.core.BeanRequest.commitTransIfRequired(BeanRequest.java:61)
    	at com.avaje.ebeaninternal.server.persist.DefaultPersister.executeOrQueue(DefaultPersister.java:113)
    	at com.avaje.ebeaninternal.server.persist.DefaultPersister.executeSqlUpdate(DefaultPersister.java:127)
    	at com.avaje.ebeaninternal.server.core.DefaultServer.execute(DefaultServer.java:1839)
    	at com.avaje.ebeaninternal.server.core.DefaultServer.execute(DefaultServer.java:1846)
    	at com.avaje.ebeaninternal.server.core.DefaultSqlUpdate.execute(DefaultSqlUpdate.java:98)
    	at com.avaje.ebean.SqlUpdate$execute.call(Unknown Source)
    	at com.bigdata.datacenter.datasync.service.impl.mysql.MysqlScanMonitorServiceImpl.updateCurrentAllDsState(MysqlScanMonitorServiceImpl.groovy:389)
    	at com.bigdata.datacenter.datasync.service.ScanMonitorService$updateCurrentAllDsState$0.call(Unknown Source)
    	at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
    	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
    	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:141)
    	at com.bigdata.datacenter.datasync.server.mysql.MysqlSubjectServer$MysqlSubjectShutdownThread.run(MysqlSubjectServer.groovy:169)

## 错误分析过程 ##

通过报错日志，可以分析出上面的错误信息是一个JAVA线程池中最常见的一个错误，由于线程池关闭而拒绝了新的任务导致的异常。

在通过查看DaemonExecutorService类的源码后，发现是由此方法抛出的异常。

/**
       * Execute the Runnable.
       */
      public void execute(Runnable runnable) {
        service.execute(runnable);
      }

即ebean的service在执行某一个SQL任务时执行报错了。

DaemonExecutorService类源码：

package com.avaje.ebeaninternal.server.lib;
 
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 
 /** * A "CachedThreadPool" based on Daemon threads. * * The Threads are created as needed and once idle live for 60 seconds. */ public final class DaemonExecutorService {
 
 private static final Logger logger = LoggerFactory.getLogger(DaemonExecutorService.class);
 
 private final String namePrefix;
 
 private final int shutdownWaitSeconds;
 
 private final ExecutorService service;
 
 /** * Construct the DaemonThreadPool. * * @param shutdownWaitSeconds the time in seconds allowed for the pool to shutdown nicely. After * this the pool is forced to shutdown. */ public DaemonExecutorService(int shutdownWaitSeconds, String namePrefix) {
 this.service = Executors.newCachedThreadPool(new DaemonThreadFactory(namePrefix));
 this.shutdownWaitSeconds = shutdownWaitSeconds;
 this.namePrefix = namePrefix;
 }
 
 /** * Execute the Runnable. */ public void execute(Runnable runnable) {
 service.execute(runnable);
 }
 
 /** * Shutdown this thread pool nicely if possible. * * This will wait a maximum of 20 seconds before terminating any threads still * working. * */ public void shutdown() {
 synchronized (this) {
 if (service.isShutdown()) {
 logger.debug("DaemonExecutorService[{}] already shut down", namePrefix);
 return;
 }
 try {
 logger.debug("DaemonExecutorService[{}] shutting down...", namePrefix);
 service.shutdown();
 if (!service.awaitTermination(shutdownWaitSeconds, TimeUnit.SECONDS)) {
 logger.info("DaemonExecutorService[{}] shut down timeout exceeded. Terminating running threads.", namePrefix);
 service.shutdownNow();
 }
 
 } catch (Exception e) {
 logger.error("Error during shutdown of DaemonThreadPool[" + namePrefix + "]", e);
 e.printStackTrace();
 }
 }
 }
 
 }

在查看DaemonExecutorService类的所有代码后，可知上面的service是新建的一个cached类型的线程池，而在生产环境中报错的时间点又是在JAR包关闭时报错的，故可以锁定是由shutdown方法导致的。由此可以猜测是在jar包关闭过程中，ebean添加了一个shutdownHook的钩子函数，函数中执行了DaemonExecutorService类中的shutdown方法。而代码 **s ervice.awaitTermination(shutdownWaitSeconds, TimeUnit.SECONDS)**中的shutdownWaitSeconds值在这里就起了很重要的作用了，在等待shutdownWaitSeconds秒后就将线程池中的所有线程释放掉，并且不再接收任何其他的新任务了。所以如果在等待shutdownWaitSeconds秒后还有新的任务要去执行，线程池已经为空了，所以就会抛出拒绝任务的异常，即：

**java.util.concurrent.RejectedExecutionException: Task com.avaje.ebeaninternal.server.transaction.PostCommitProcessing$$Lambda$2/1368391951@6edfcc61 rejected from java.util.concurrent.ThreadPoolExecutor@31956fb3\[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 16969\]**

为了进一步验证此种臆想，通过IDEA的工具可查询到调用此shutdown的具体类在哪里。

![70][]

通过查询shutdown方法调用层可以看到是在ShutdownManager.shutdown()这个方法中有主动调用的。而具体的为ShutdownHook.run()这个方法。

再进一步查看ShutdownManager的具体源码：

package com.avaje.ebeaninternal.server.lib;
 
 import com.avaje.ebean.common.SpiContainer;
 import com.avaje.ebeaninternal.api.ClassUtil;
 import com.avaje.ebeaninternal.api.SpiEbeanServer;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import java.sql.Driver;
 import java.sql.DriverManager;
 import java.sql.SQLException;
 import java.util.ArrayList;
 import java.util.Enumeration;
 import java.util.List;
 
 /** * Manages the shutdown of the JVM Runtime. * * Makes sure all the resources are shutdown properly and in order. * */ public final class ShutdownManager {
 
 private static final Logger logger = LoggerFactory.getLogger(ShutdownManager.class);
 
 static final List<SpiEbeanServer> servers = new ArrayList<>();
 
 static final ShutdownHook shutdownHook = new ShutdownHook();
 
 static boolean stopping;
 
 static SpiContainer container;
 
 static {
 // Register the Shutdown hook
 registerShutdownHook();
 }
 
 /** * Disallow construction. */ private ShutdownManager() {
 }
 
 public static void registerContainer(SpiContainer ebeanContainer) {
 container = ebeanContainer;
 }
 
 /** * Make sure the ShutdownManager is activated. */ public static void touch() {
 // Do nothing
 }
 
 /** * Return true if the system is in the process of stopping. */ public static boolean isStopping() {
 synchronized (servers) {
 return stopping;
 }
 }
 
 /** * Deregister the Shutdown hook. * * In calling this method it is expected that application code will invoke * the shutdown() method. * * * For running in a Servlet Container a redeploy will cause a shutdown, and * for that case we need to make sure the shutdown hook is deregistered. * */ public static void deregisterShutdownHook() {
 synchronized (servers) {
 try {
 Runtime.getRuntime().removeShutdownHook(shutdownHook);
 } catch (IllegalStateException ex) {
 if (!ex.getMessage().equals("Shutdown in progress")) {
 throw ex;
 }
 }
 }
 }
 
 /** * Register the shutdown hook with the Runtime. */ protected static void registerShutdownHook() {
 synchronized (servers) {
 try {
 String value = System.getProperty("ebean.registerShutdownHook");
 if (value == null || !value.trim().equalsIgnoreCase("false")) {
 Runtime.getRuntime().addShutdownHook(shutdownHook);
 }
 } catch (IllegalStateException ex) {
 if (!ex.getMessage().equals("Shutdown in progress")) {
 throw ex;
 }
 }
 }
 }
 
 /** * Shutdown gracefully cleaning up any resources as required. * * This is typically invoked via JVM shutdown hook. * */ public static void shutdown() {
 synchronized (servers) {
 if (stopping) {
 // Already run shutdown...
 return;
 }
 
 if (logger.isDebugEnabled()) {
 logger.debug("Shutting down");
 }
 
 stopping = true;
 
 deregisterShutdownHook();
 
 String shutdownRunner = System.getProperty("ebean.shutdown.runnable");
 if (shutdownRunner != null) {
 try {
 // A custom runnable executed at the start of shutdown
 Runnable r = (Runnable) ClassUtil.newInstance(shutdownRunner);
 r.run();
 } catch (Exception e) {
 logger.error("Error running custom shutdown runnable", e);
 }
 }
 
 if (container != null) {
 // shutdown cluster networking if active
 container.shutdown();
 }
 
 // shutdown any registered servers that have not
 // already been shutdown manually
 for (SpiEbeanServer server : servers) {
 try {
 server.shutdownManaged();
 } catch (Exception ex) {
 logger.error("Error executing shutdown runnable", ex);
 ex.printStackTrace();
 }
 }
 
 if ("true".equalsIgnoreCase(System.getProperty("ebean.datasource.deregisterAllDrivers", "false"))) {
 deregisterAllJdbcDrivers();
 }
 }
 }
 
 private static void deregisterAllJdbcDrivers() {
 // This manually deregisters all JDBC drivers
 Enumeration<Driver> drivers = DriverManager.getDrivers();
 while (drivers.hasMoreElements()) {
 Driver driver = drivers.nextElement();
 try {
 logger.info("Deregistering jdbc driver: " + driver);
 DriverManager.deregisterDriver(driver);
 } catch (SQLException e) {
 logger.error("Error deregistering driver " + driver, e);
 }
 }
 }
 
 /** * Register an ebeanServer to be shutdown when the JVM is shutdown. */ public static void registerEbeanServer(SpiEbeanServer server) {
 synchronized (servers) {
 servers.add(server);
 }
 }
 
 /** * Deregister an ebeanServer. * * This is done when the ebeanServer is shutdown manually. * */ public static void unregisterEbeanServer(SpiEbeanServer server) {
 synchronized (servers) {
 servers.remove(server);
 }
 }
 }

package com.avaje.ebeaninternal.server.lib;
    
    
    /** * This is the ShutdownHook that gets added to Runtime. * It will try to shutdown the system cleanly when the JVM exits. * It is best to add your own shutdown hooks to StartStop. */ class ShutdownHook extends Thread {
    
      ShutdownHook() {
      }
    
      /** * Fired by the JVM Runtime on shutdown. */ public void run() {
        ShutdownManager.shutdown();
      }
    
    }

由此可以确定，在ebean框架启动的时候绑定了一个shutdownHook函数，由它来处理ebean关闭时的一些操作。

通过上面的分析，如果要解决本文头的报错，需要将ebean关闭时的等待时间设长一点就好了,也就是DaemonExecutorService  类中的shutdownWaitSeconds的值，那么这个值又在哪里设的呢？

在通过进一步查询源码后，发现是在ServerConfig这个类中配置的，并且关闭时的默认等待时间为30秒

private int backgroundExecutorShutdownSecs = 30;  
    /**
       * Return the Background executor shutdown seconds. This is the time allowed for the pool to shutdown nicely
       * before it is forced shutdown.
       */
      public int getBackgroundExecutorShutdownSecs() {
        return backgroundExecutorShutdownSecs;
      }
    
      /**
       * Set the Background executor shutdown seconds. This is the time allowed for the pool to shutdown nicely
       * before it is forced shutdown.
       */
      public void setBackgroundExecutorShutdownSecs(int backgroundExecutorShutdownSecs) {
        this.backgroundExecutorShutdownSecs = backgroundExecutorShutdownSecs;
      }

##     ##

## 解决办法 ##

于是解决办法就有了：根据项目的功能需要，配置对应的关闭等待时间即可。

如果是在ebean是在spring的xml中配置，可以这样配置(将关闭时间修改为10分钟，即60\*10秒):

[70]: /images/20220521/97e61e2a78be485097a0d84250421d7a.png