記一次生產頻繁發生FullGC問題

theonenini發表於2023-03-16
GC
 

問題發現

早上過來，飯都沒來的及吃，運維就給我發來資訊，說是某個介面呼叫大量超時。因為最近這個介面呼叫量是翻倍了，所以我就去檢查了下慢SQL，發現確實是有較多的慢SQL，所以我就縮減了查詢的時間範圍，但是效果並不好。
過了一會發現，這個服務fullGC是有問題的，太頻繁了，這個應該是導致介面超時的根本問題，因為時間也是對的上的。
這個是最近三個小時fullGC的監控圖：
0
這個是最近三天fullGC的監控圖：
0
對比一下，就不難發現，fullGC數量是從3月15號晚上9點開始增加的，也是這個介面對外開放的時間。
 

解決思路

1、首先去伺服器上面下載dump檔案，分析是哪裡造成了記憶體洩漏，頻繁觸發fullGC。首先找出伺服器內java檔案的PID，然後儲存dump檔案，我們公司java服務是固定埠號：1

使用top命令：
0
然後執行命令：jmap -dump:file=202303160924.dump,format=b 1 ，儲存dump檔案
0

2、根據dump檔案，分析出堆內物件的分佈情況

    • 下載一個可以分析dump檔案的工具，這裡我下載是Jprofiler
    • 檢視大物件的分析，發現是java.lang.ApplicationShutdownHooks的hooks佔用太大記憶體，並且得知改熟悉是一個Map
0
    • 分析這個Map裡面的元素引用關係，可以看到這個map裡面存的都是執行緒物件，並且大部分都是一個名為java.util.concurrent.ScheduledThreadPoolExecutor@59648a61的執行緒池物件，到了這裡就定位到問題程式碼了，是這次新加的介面裡面有一個非同步操作，用的guava併發包裡面的一個超時等待功能的介面，具體思路就是啟用一個定時任務執行緒池去定時去檢查在規定時間內，是否返回結果。
  0

3、看看我的業務程式碼是哪裡出現了問題

//非同步執行某個查詢方法，並且在規定時間內返回查詢結果
public <T> T asyncWithTimeout(ScheduledThreadPoolExecutor executor, Callable<T> callable,
                              long time, TimeUnit unit) {
    try {
        ListeningExecutorService listeningExecutorService = MoreExecutors.listeningDecorator(threadPoolExecutor);
        ListenableFuture<T> future = listeningExecutorService.submit(callable);
        //這裡是建立一個定時任務執行緒，去定時檢查是否在規定時間內查詢完畢，應該就是這個去新增了鉤子函式，進去看看
        ScheduledExecutorService scheduledExecutorService = MoreExecutors.getExitingScheduledExecutorService(executor);
        return Futures.withTimeout(future, time, unit, scheduledExecutorService).get(time, unit);
    } catch (InterruptedException | ExecutionException | TimeoutException e) {
        log.warn("非同步方法執行失敗，error:{}", e.getMessage());
    }
    return null;
}

//=======================guava併發包程式碼=======================

@Beta
@GwtIncompatible // TODO
public static ScheduledExecutorService getExitingScheduledExecutorService(
    ScheduledThreadPoolExecutor executor) {
  //每次都去建立一個新的物件
  return new Application().getExitingScheduledExecutorService(executor);
}

final ScheduledExecutorService getExitingScheduledExecutorService(
    ScheduledThreadPoolExecutor executor) {
  return getExitingScheduledExecutorService(executor, 120, TimeUnit.SECONDS);
}

final ScheduledExecutorService getExitingScheduledExecutorService(
    ScheduledThreadPoolExecutor executor, long terminationTimeout, TimeUnit timeUnit) {
  useDaemonThreadFactory(executor);
  ScheduledExecutorService service = Executors.unconfigurableScheduledExecutorService(executor);
  //新增建構函式的地方，進去看看
  addDelayedShutdownHook(executor, terminationTimeout, timeUnit);
  return service;
}

final void addDelayedShutdownHook(
    final ExecutorService service, final long terminationTimeout, final TimeUnit timeUnit) {
  checkNotNull(service);
  checkNotNull(timeUnit);
  //繼續點進去
  addShutdownHook(
      MoreExecutors.newThread(
          //執行緒名字對上了，就在物件引用的截圖裡面出現過
          "DelayedShutdownHook-for-" + service,
          new Runnable() {
            @Override
            public void run() {
              try {
                // We'd like to log progress and failures that may arise in the
                // following code, but unfortunately the behavior of logging
                // is undefined in shutdown hooks.
                // This is because the logging code installs a shutdown hook of its
                // own. See Cleaner class inside {@link LogManager}.
                service.shutdown();
                service.awaitTermination(terminationTimeout, timeUnit);
              } catch (InterruptedException ignored) {
                // We're shutting down anyway, so just ignore.
              }
            }
          }));
}

@VisibleForTesting
void addShutdownHook(Thread hook) {
  Runtime.getRuntime().addShutdownHook(hook);
}

//=======================guava併發包程式碼=======================

public void addShutdownHook(Thread hook) {
    SecurityManager sm = System.getSecurityManager();
    if (sm != null) {
        sm.checkPermission(new RuntimePermission("shutdownHooks"));
    }
    //定位到問題了，就是這裡新增的鉤子函式
    ApplicationShutdownHooks.add(hook);
}

static synchronized void add(Thread hook) {
    if(hooks == null)
        throw new IllegalStateException("Shutdown in progress");

    if (hook.isAlive())
        throw new IllegalArgumentException("Hook already running");

    if (hooks.containsKey(hook))
        throw new IllegalArgumentException("Hook previously registered");

    //存在到 hooks 這個map物件裡面，就是這個大物件
    hooks.put(hook, hook);
}

問題解決

經過上面問題的排查，造成hooks大物件的原因找到了，就是每次呼叫介面的時候，都會往hooks裡面put一個物件。
所以，解決辦法很簡單，就是不用每次都去生成一個ScheduledExecutorService物件，類初始化的時候建立一次就行了
改造後的程式碼如下：
private ListeningExecutorService listeningExecutorService;
private ScheduledExecutorService scheduledExecutorService;

public static AsyncUtils getInstance() {
    return ThreadHolder.INSTANCE.getAsyncWithCallback();
}

@SuppressWarnings("UnstableApiUsage")
private AsyncUtils() {
    listeningExecutorService = MoreExecutors.listeningDecorator(ThreadPoolConstant.THREAD_POOL_EXECUTOR);
    scheduledExecutorService = MoreExecutors.getExitingScheduledExecutorService(ThreadPoolConstant.SCHEDULED_THREAD_POOL_EXECUTOR);
}

@SuppressWarnings("UnstableApiUsage")
public <T> T asyncWithTimeout(Callable<T> callable,
                              long time, TimeUnit unit) {
    try {
        ListenableFuture<T> future = listeningExecutorService.submit(callable);
        return Futures.withTimeout(future, time, unit, scheduledExecutorService).get(time, unit);
    } catch (InterruptedException | ExecutionException | TimeoutException e) {
        log.warn("非同步方法執行失敗，error:{}", e.getMessage());
    }
    return null;
}

private enum ThreadHolder {
    /**
     * 執行緒持有類 INSTANCE
     */
    INSTANCE;
    private final AsyncUtils asyncUtils;

    ThreadHolder() {
        asyncUtils = new AsyncUtils();
    }

    public AsyncUtils getAsyncWithCallback() {
        return asyncUtils;
    }
}
 

相關文章