一次生產環境OOM排查

烟味i發表於2024-03-01

一、背景

前幾天下午飛書告警群裡報起了java.lang.OutOfMemoryError: unable to create new native thread告警,看見後艾特了對應的專案負責人但是負責人說沒時間,無奈自己親自上陣。

二、事情經過

2.1 問題排查

從報錯資訊就可以看出是服務申請不到足夠的記憶體去建立新的執行緒導致的,熟悉JVM的都知道執行緒用的是虛擬機器棧記憶體,這裡是虛擬機器棧記憶體不夠跟堆沒有關係。

然後立馬登入阿里雲進入容器使用如下命令dump出執行緒堆疊

jstack -l 1 > dump.log

讓運維幫我把檔案下載下來後,就把dump.log上傳到網站https://fastthread.io/進行分析,分析結果如下:

執行緒總覽

可以看到服務的執行緒數竟然高達2000多個!!!而且也給出來警告這麼高的執行緒數可能導致OOM,那麼問題原因就很清楚了就是執行緒數過多導致的,那麼是哪些執行緒過多呢?

執行緒數量排行

第二張圖顯示數量做多的是名字為com.alibaba.nacos.client.Worker的執行緒,並且排行前三名都是nacos的執行緒,我一度懷疑是nacos出bug了🤣🤣🤣

再點進去看看對應的執行緒堆疊如下圖:

執行緒堆疊

可以看出執行緒阻塞在從佇列獲取任務那裡,說明這些執行緒都是沒活幹,空閒掛起的,具體看不出問題原因,只能看程式碼了。

開啟專案,使用idea全域性搜尋com.alibaba.nacos.client.Worker,發現是ClientWorker類在構造方法裡建立了一個定時執行緒池,執行緒名稱就叫com.alibaba.nacos.client.Worker,其中核心執行緒數是4。

繼續跟蹤原始碼,發現只有在NacosConfigService的構造方法裡呼叫了ClientWorke的構造方法。

但是點選NacosConfigService的構造方法卻發現沒有呼叫,這是什麼情況呢?

點選其父類com.alibaba.nacos.api.config.ConfigService查詢引用可以看到有個NacosFactory的工廠類,原來ConfigService的是例項是透過工廠方法建立的,而工廠方法內部是透過反射建立的,如下圖。

最終找到了業務類NacosConfigServiceImpl如下圖:

@Slf4j
@Component
public class NacosConfigServiceImpl implements ConfigService {

    /**
     * nacos地址key
     */
    public static final String SERVER_ADDR = "spring.cloud.nacos.config.server-addr";

    /**
     * nacos配置namespace
     */
    public static final String CONFIG_NAMESPACE = "spring.cloud.nacos.config.namespace";

    @Getter
    @Value("${spring.cloud.nacos.config.group}")
    private String groupId;

    @Value("${" + SERVER_ADDR + "}")
    private String nacosServerAddr;

    @Value("${" + CONFIG_NAMESPACE + "}")
    private String nacosConfigNamespace;

    private ConfigService configService;

    private static final long TIMEOUT_MILLIS = 3000L;

    @PostConstruct
    public void init() throws NacosException {
        this.configService = getConfigService();
    }

    @Override
    public void registerListener(String dataId, ConfigListener configListener) {
        AssertUtil.that(StringUtils.isNotBlank(dataId), BasicErrorCode.PARAM_ERROR, "dataId empty");
        AssertUtil.that(configListener != null, BasicErrorCode.PARAM_ERROR, "configListener null");

        try {
            //註冊監聽器
            // 第一次建立
            ConfigService configService = getConfigService();
            configService.addListener(dataId, getGroupId(), new DefaultListener(dataId, configListener));

            //首次更新配置
            // 第二次建立
            String configInfo = getConfigInfo(dataId);
            configListener.receiveConfigInfo(configInfo);

            log.info(LogUtil.message("registerListener success",
                    dataId, InvokeLineUtil.simplifiedClassName(configListener)));
        } catch (Exception e) {
            log.error(LogUtil.exceptionMessage("registerListener exception", e, dataId, configListener));
            throw new ApiException(BasicErrorCode.CONFIG_ERROR, e.getMessage());
        }
    }

    @Override
    public String getConfigInfo(String dataId) {
        try {
            ConfigService configService = getConfigService();
            return configService.getConfig(dataId, getGroupId(), TIMEOUT_MILLIS);
        } catch (Exception e) {
            log.error(LogUtil.exceptionMessage("getConfigInfo exception", e, dataId));
            throw new ApiException(BasicErrorCode.CONFIG_ERROR, e.getMessage());
        }
    }

    private ConfigService getConfigService() throws NacosException {
        Properties properties = new Properties();
        properties.put(PropertyKeyConst.SERVER_ADDR, nacosServerAddr);
        properties.put(PropertyKeyConst.NAMESPACE, nacosConfigNamespace);
        // 呼叫工廠方法建立configService
        ConfigService configService = NacosFactory.createConfigService(properties);
        return configService;
    }

}

當時看到上面程式碼我都驚呆了,既然已經在init()方法裡初始化了屬性configService,為什麼還要在registerListener()方法裡兩次呼叫getConfigService()去建立兩次configService例項呢?

然後找了下registerListener()方法的呼叫,發現多達50處!

問題原因大概就清楚了,nacos的configService設計上是作為單例去使用的,但是被濫用導致建立了很多執行緒池和執行緒把虛擬機器棧記憶體耗盡,再申請建立新執行緒時就報了OOM

2.2 相關疑問

此時同事小A提出疑問,registerListener()方法執行完了,configService物件就會被gc回收,對應的執行緒池不也是被回收了嗎?

這個問題看似很有道理其實不然,物件能不能回收是看這個物件到GC Root還有沒有可達路徑,執行緒池的gc root其實是執行緒,對應的gc路徑是thread->workers->執行緒池,因為那些nacos執行緒池也沒有設定屬性allowCoreThreadTimeOut(true),所以就算執行緒空閒了核心執行緒也不會回收。
如果我們要在方法裡建立並使用執行緒池,用完一定要記得呼叫shutdown方法,這樣執行緒池才會被回收,當然更推薦執行緒池作為單例bean注入Spring容器使用。

愛專研的同事A又說你這執行緒數也對不上啊,50x4x2=400也沒到500個啊。

大家有興趣的可以去看看原始碼,NacosConfigService的構造方法裡的ServerListManager類內部也有一個執行緒池,而且前面執行緒數量排行圖中第三名的com.alibaba.nacos.client.remote.worker執行緒也跟這個有關。

2.3 解決方案

知道了原因解決起來就很快了,NacosConfigServiceImpl#registerListener()方法裡建立configSerivce的程式碼改成用單例屬性就行了。

三、總結

在用第三方開源元件的時候還是要多看看文件和其原始碼,使用正確的姿勢不要一上來就擼程式碼,否則很容易產生生產事故。
不過在排查問題的過程中也順便看了下nacos服務端和客戶端配置同步的實現,算還有點收穫吧。

相關文章