你要偷偷學會排查線上CPU飆高的問題，然後驚豔所有人！

HollisChuang發表於2021-03-31

前段時間我們新上了一個新的應用，因為流量一直不大，叢集QPS大概只有5左右，寫介面的rt在30ms左右。

因為最近接入了新的業務，業務方給出的資料是日常QPS可以達到2000，大促峰值QPS可能會達到1萬。

所以，為了評估水位，我們進行了一次壓測。壓測在預釋出環境執行。壓測過程中發現，當單機QPS達到200左右時，介面的rt沒有明顯變化，但是CPU利用率急劇升高，直到被打滿。

-w1460

壓測停止後，CPU利用率立刻降了下來。

於是開始排查是什麼導致了CPU的飆高。

問題排查與解決

在壓測期間，登入到機器，開始排查問題。

本案例的排查過程使用的阿里開源的Arthas工具進行的，不使用arthas，使用JDK自帶的命令也是可以。

在開始排查之前，可以先看一下CPU的使用情況，最簡單的就是使用top命令直接檢視：

top - 10:32:38 up 11 days, 17:56,  0 users,  load average: 0.84, 0.33, 0.18
Tasks:  23 total,   1 running,  21 sleeping,   0 stopped,   1 zombie
%Cpu(s): 95.5 us,  2.2 sy,  0.0 ni, 76.3 id,  0.0 wa,  0.0 hi,  0.0 si,  6.1 st
KiB Mem :  8388608 total,  4378768 free,  3605932 used,   403908 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  4378768 avail Mem
   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND  
   3480 admin     20   0 7565624   2.9g   8976 S  241.2 35.8 649:07.23 java  
   1502 root      20   0  401768  40228   9084 S   1.0  0.5  39:21.65 ilogtail
   181964 root      20   0 3756408 104392   8464 S   0.7  1.2   0:39.38 java   
   496 root      20   0 2344224  14108   4396 S   0.3  0.2  52:22.25 staragentd  
   1400 admin     20   0 2176952 229156   5940 S   0.3  2.7  31:13.13 java
   235514 root      39  19 2204632  15704   6844 S   0.3  0.2  55:34.43 argusagent
   236226 root      20   0   55836   9304   6888 S   0.3  0.1  12:01.91 systemd-journ

可以看到，程式ID為3480的Java程式佔用的CPU比較高，基本可以斷定是應用程式碼執行過程中消耗了大量CPU，接下來開始排查具體是哪個執行緒，哪段程式碼比較耗CPU。

首先，下載Arthas命令：

curl -L http://start.alibaba-inc.com/install.sh | sh

啟動

./as.sh

使用Arthas命令"thread -n 3 -i 1000"檢視當前"最忙"（耗CPU）的三個執行緒：

-w1147

通過上面的堆疊資訊，可以看出，佔用CPU資源的執行緒主要是卡在JDBC底層的TCP套接字讀取上。連續執行了很多次，發現很多執行緒都是卡在這個地方。

通過分析呼叫鏈，發現這個地方是我程式碼中有資料庫的insert，並且使用TDDL來建立sequence，在sequence的建立過程中需要和資料庫有互動。

但是，基於對TDDL的瞭解，TDDL每次從資料庫中查詢sequence序列的時候，預設會取出1000條，快取在本地，只有用完之後才會再從資料庫獲取下一個1000條序列。

按理說我們的壓測QPS只有300左右，不應該這麼頻繁的何資料庫互動才對。但是，經過多次使用arthas的檢視，發現大部分CPU都耗盡在這裡。

於是開始排查程式碼問題。最終發現了一個很傻的問題，那就是我們的sequence建立和使用有問題：

public Long insert(T dataObject) {

    if (dataObject.getId() == null) {
        Long id = next();
        dataObject.setId(id);
    }

    if (sqlSession.insert(getNamespace() + ".insert", dataObject) > 0) {
        return dataObject.getId();
    } else {
        return null;
    }
}

public Sequence sequence() {
    return SequenceBuilder.create()
        .name(getTableName())
        .sequenceDao(sequenceDao)
        .build();
}

/**
 * 獲取下一個主鍵ID
 *
 * @return
 */
protected Long next() {
    try {
        return sequence().nextValue();
    } catch (SequenceException e) {
        throw new RuntimeException(e);
    }
}

是因為，我們每次insert語句都重新build了一個新的sequence，這就導致本地快取就被丟掉了，所以每次都會去資料庫中重新拉取1000條，但是隻是用了一條，下一次就又重新取了1000條，周而復始。

於是，調整了程式碼，把Sequence例項的生成改為在應用啟動時初始化一次。這樣後面在獲取sequence的時候，不會每次都和資料庫互動，而是先查本地快取，本地快取的耗盡了才會再和資料庫互動，獲取新的sequence。

public abstract class BaseMybatisDAO implements InitializingBean {
        @Override
        public void afterPropertiesSet() throws Exception {
            sequence = SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build();
        }
    }

通過實現InitializingBean，並且重寫afterPropertiesSet()方法，在這個方法中進行Sequence的初始化。

改完以上程式碼，提交進行驗證。通過監控資料可以看出優化後，資料庫的讀RT有明顯下降：