背景介紹

業(yè)務(wù)介紹

在某學(xué)習(xí)App瀏覽文章，客戶端會(huì)將瀏覽的文章信息上傳到服務(wù)端，服務(wù)端將瀏覽信息最終存儲(chǔ)到HBase；
在某學(xué)習(xí)APP首頁點(diǎn)擊【我的】->【歷史】，會(huì)展示用戶瀏覽文章的歷史記錄。

技術(shù)介紹

服務(wù)端的服務(wù)是【閱讀歷史離線服務(wù)】，從metaq消費(fèi)用戶閱讀文章的信息，解析、處理相關(guān)業(yè)務(wù)邏輯，最后存儲(chǔ)到HBase。

問題現(xiàn)象

ECS監(jiān)控

兩臺(tái)機(jī)器【xx-xxxx-xxx-xxx-xxx-xxx-6、xx-xxx-xxx-xxx-xxx-xxx-1】在早高峰的時(shí)候Load很高，CPU使用率正常。

metaq監(jiān)控

造成消息消費(fèi)的慢，每天早上都有大量消息堆積，導(dǎo)致用戶看不到自己的閱讀歷史。

問題分析

基本情況

【閱讀歷史離線服務(wù)】共有x臺(tái)ECS，每臺(tái)ECS配置是8c16g。其中x臺(tái)機(jī)器正常，2臺(tái)機(jī)器不正常。

排查思路

找不同

分析不正常機(jī)器與正常機(jī)器有哪些差異：對(duì)比了【應(yīng)用程序版本】、【應(yīng)用程序配置】、【JVM配置參數(shù)】、【JDK版本】、【操作系統(tǒng)版本】，發(fā)現(xiàn)【JDK版本】不一致。
正常機(jī)器：

openjdk version "1.8.0_171"
OpenJDK Runtime Environment (build 1.8.0_171-b10)
OpenJDK 64-Bit Server VM (build 25.171-b10, mixed mode)

異常機(jī)器：

openjdk version "1.8.0_222"
OpenJDK Runtime Environment (build 1.8.0_222-b10)
OpenJDK 64-Bit Server VM (build 25.222-b10, mixed mode)

到此初步定位不同機(jī)器運(yùn)行狀態(tài)不一致的現(xiàn)象是由于【JDK版本】不一致造成的，所以將【問題機(jī)器的JDK版本】替換為【正常機(jī)器的JDK版本】問題就可以解決了。

定位問題代碼

但是問題的根因還需要嘗試排查一下，既然是【JDK版本】不一致造成的，那么會(huì)不會(huì)是【1.8.0_222】這個(gè)版本中有BUG，剛好我們寫的程序觸發(fā)了這個(gè)BUG？
所以接下來需要弄清楚程序運(yùn)行過程中執(zhí)行了哪些業(yè)務(wù)邏輯、這些業(yè)務(wù)邏輯涉及到了哪些JDK API，直接想到的工具是arthas profiler，下面是抓到的熱點(diǎn)方法。
通過對(duì)比【異常機(jī)器】與【正常機(jī)器】的熱點(diǎn)方法，發(fā)現(xiàn)Runtime.getRuntime().availableProcessors()很可疑：

業(yè)務(wù)相關(guān)代碼：

CompletableFuture<Result> completableFuture = //業(yè)務(wù)邏輯，調(diào)用hbase-client中api
completableFuture.whenCompleteAsync((result, t) -> {
   //業(yè)務(wù)邏輯處理            
}, Pool.getSubmitPool()).exceptionally((t) -> {
   //業(yè)務(wù)邏輯處理
}).get();

CompletableFuture相關(guān)代碼:

/**
     * Waits if necessary for this future to complete, and then
     * returns its result.
     *
     * @return the result value
     * @throws CancellationException if this future was cancelled
     * @throws ExecutionException if this future completed exceptionally
     * @throws InterruptedException if the current thread was interrupted
     * while waiting
     */
    public T get() throws InterruptedException, ExecutionException {
        Object r;
        return reportGet((r = result) == null ? waitingGet(true) : r);
    }
/**
     * Returns raw result after waiting, or null if interruptible and
     * interrupted.
     */
    private Object waitingGet(boolean interruptible) {
        Signaller q = null;
        boolean queued = false;
        int spins = -1;
        Object r;
        while ((r = result) == null) {
            if (spins < 0)
                spins = (Runtime.getRuntime().availableProcessors() > 1) ?
                    1 << 8 : 0; // Use brief spin-wait on multiprocessors
            else if (spins > 0) {
                if (ThreadLocalRandom.nextSecondarySeed() >= 0)
                    --spins;
            }
            else if (q == null)
                q = new Signaller(interruptible, 0L, 0L);
            else if (!queued)
                queued = tryPushStack(q);
            else if (interruptible && q.interruptControl < 0) {
                q.thread = null;
                cleanStack();
                return null;
            }
            else if (q.thread != null && result == null) {
                try {
                    ForkJoinPool.managedBlock(q);
                } catch (InterruptedException ie) {
                    q.interruptControl = -1;
                }
            }
        }
        if (q != null) {
            q.thread = null;
            if (q.interruptControl < 0) {
                if (interruptible)
                    r = null; // report interruption
                else
                    Thread.currentThread().interrupt();
            }
        }
        postComplete();
        return r;
    }

猜測(cè)驗(yàn)證

public class Processors {
    public static void main(String []args) {
        int availableProcessors = Runtime.getRuntime().availableProcessors();
        System.out.println("Available Processors: " + availableProcessors);
        
        for(int i = 0;i < availableProcessors;i++){
            Thread t = new Thread(()-> {
                    while (true){
                        try {
                            int ps = Runtime.getRuntime().availableProcessors();
                            Thread.sleep(1L);
                        }catch (Exception e){
                            e.printStackTrace();
                        }
                    }
            });

            t.start();
        }
    }
}

將驗(yàn)證代碼在【JDK版本】為【1.8.0_222】的機(jī)器上運(yùn)行，隨即復(fù)現(xiàn)了線上問題。

定位根因

那么【1.8.0_222】與【1.8.0_171】版本在Runtime.getRuntime().availableProcessors()的實(shí)現(xiàn)上有什么差別呢？【1.8.0_222】增加了容器環(huán)境的邏輯，比【1.8.0_171】復(fù)雜了很多。
最后我們看看在
https://bugs.openjdk.JAVA.NET/的解釋吧。

總結(jié)：
Runtime.getRuntime().availableProcessors()在不同JDK版本上的實(shí)現(xiàn)是沒有問題的，
CompletableFuture.waitingGet在【1.8.0_222】版本上，沒有測(cè)試到Runtime.getRuntime().availableProcessors()對(duì)性能的影響，導(dǎo)致了性能問題。

解決方法

openjdk在1.8.0_191~1.8.0_222之間的版本都存在問題，換成1.8.0_191之前，或1.8.0_232及以后的版本可以。

問題根因

CompletableFuture.get()的實(shí)現(xiàn)方式在一些jdk版本存在缺陷，
詳情見：[JDK-8227018] CompletableFuture should not call
Runtime.availableProcessors on fast path - Java Bug System