Find N3入網(wǎng)：最高支持16+1TB
OPPO將于近期登場的Find N3折疊屏目前已經(jīng)正式入網(wǎng)，型號(hào)為PHN110。本次Find N3在外觀方面相比前兩代有很大的變化，不再是小號(hào)的橫向折疊屏，而是跟別的廠商一樣采用了較為常見的
前段時(shí)間我們新上線了一個(gè)應(yīng)用，由于流量一直不大，集群的每秒查詢率（QPS）大約只有 5。接口的響應(yīng)時(shí)間大約在 30 毫秒左右。
最近我們接入了新的業(yè)務(wù)，業(yè)務(wù)方提供的數(shù)據(jù)顯示，日常的 QPS 預(yù)計(jì)可以達(dá)到 2000，而在大促期間峰值 QPS 可能會(huì)達(dá)到 1 萬。
為了評(píng)估系統(tǒng)的性能水平，我們進(jìn)行了一次壓力測試。測試在預(yù)發(fā)布環(huán)境進(jìn)行。在壓力測試過程中，我們觀察到當(dāng)單臺(tái)服務(wù)器的 QPS 達(dá)到約 200 時(shí)，接口的響應(yīng)時(shí)間沒有明顯變化，但是 CPU 利用率迅速上升，直到達(dá)到極限。
圖片
壓力測試結(jié)束后，CPU 利用率立即下降。
隨后我們開始排查是什么原因?qū)е铝?CPU 的突然飆升。
在壓力測試期間，登錄到機(jī)器后，我們開始排查問題。
本案例的排查過程使用了阿里開源的 Arthas 工具。如果沒有 Arthas，也可以使用 JDK 自帶的命令進(jìn)行排查。
在開始具體排查之前，可以先查看 CPU 的使用情況。最簡單的方法是使用top命令直接查看：
top - 10:32:38 up 11 days, 17:56, 0 users, load average: 0.84, 0.33, 0.18Tasks: 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 stKiB Mem : 8388608 total, 4378768 free, 3605932 used, 403908 buff/cacheKiB 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可以清楚的看到，進(jìn)程 ID 為 3480 的 Java 進(jìn)程占用了較高的 CPU，可以初步推斷是應(yīng)用代碼執(zhí)行過程中消耗了大量的 CPU 資源。接下來，我們需要進(jìn)一步排查是哪個(gè)線程、哪段代碼導(dǎo)致了這種情況。
首先，我們需要下載 Arthas 工具：
curl -L https://arthas.aliyun.com/install.sh | sh啟動(dòng)：
./as.sh使用 Arthas 命令 "thread -n 3 -i 1000"查看當(dāng)前"最忙"（耗 CPU）的三個(gè)線程：
圖片
通過上述堆棧信息可以看出，占用 CPU 資源的線程主要是在 JDBC 底層的 TCP 套接字讀取上阻塞。經(jīng)過連續(xù)執(zhí)行多次分析，發(fā)現(xiàn)很多線程都在這個(gè)地方卡住。
進(jìn)一步分析調(diào)用鏈后發(fā)現(xiàn)，這個(gè)問題源自于我代碼中的數(shù)據(jù)庫 insert 操作，其中使用了 TDDL 來創(chuàng)建 sequence。在 sequence 的創(chuàng)建過程中，需要與數(shù)據(jù)庫進(jìn)行交互。
根據(jù)對(duì) TDDL 的了解，它每次從數(shù)據(jù)庫查詢 sequence 序列時(shí)，默認(rèn)會(huì)獲取 1000 條，并在本地進(jìn)行緩存，直到使用完這 1000 條序列之后才會(huì)再次從數(shù)據(jù)庫獲取下一個(gè) 1000 條序列。
考慮到我們的壓測 QPS 僅約為 300 左右，不應(yīng)該導(dǎo)致如此頻繁的數(shù)據(jù)庫交互。然而，通過多次使用 Arthas 進(jìn)行查看，發(fā)現(xiàn)大部分的 CPU 資源都耗費(fèi)在這里。
因此，我們開始排查代碼問題。最終，發(fā)現(xiàn)了一個(gè)非常簡單的問題，即我們的 sequence 創(chuàng)建和使用存在著明顯的缺陷：
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();}/** * 獲取下一個(gè)主鍵ID * * @return */protected Long next() { try { return sequence().nextValue(); } catch (SequenceException e) { throw new RuntimeException(e); }}因此，我們每次執(zhí)行 insert 語句時(shí)都重新構(gòu)建了一個(gè)新的 sequence 對(duì)象，這導(dǎo)致本地緩存被清空。因此，每次都需要從數(shù)據(jù)庫重新獲取 1000 條 sequence，但實(shí)際上只使用了一條，下次又會(huì)重復(fù)這個(gè)過程。
為了解決這個(gè)問題，我們調(diào)整了代碼，在應(yīng)用啟動(dòng)時(shí)初始化了一個(gè) Sequence 實(shí)例。這樣，在后續(xù)獲取 sequence 時(shí)，不會(huì)每次都與數(shù)據(jù)庫交互。而是首先檢查本地緩存，只有在本地緩存用盡時(shí)才會(huì)再次與數(shù)據(jù)庫交互，獲取新的 sequence。
public abstract class BaseMybatisDAO implements InitializingBean { @Override public void afterPropertiesSet() throws Exception { sequence = SequenceBuilder.create().name(getTableName()).sequenceDao(sequenceDao).build(); } }通過實(shí)現(xiàn) InitializingBean 接口，并重寫其中的 afterPropertiesSet()方法，在該方法中進(jìn)行 Sequence 的初始化。
完成以上代碼修改后，提交并進(jìn)行驗(yàn)證。根據(jù)監(jiān)控?cái)?shù)據(jù)顯示，優(yōu)化后數(shù)據(jù)庫的讀取響應(yīng)時(shí)間（RT）明顯下降。
圖片
sequence 的寫操作 QPS 也有明顯下降：
圖片
于是我們開始了新的一輪壓測，但是發(fā)現(xiàn) CPU 的使用率仍然很高，壓測的 QPS 還是無法達(dá)到預(yù)期。因此，我們決定重新使用 Arthas 工具查看線程的情況。
圖片
發(fā)現(xiàn)了一個(gè) CPU 消耗較高的線程堆棧，主要是因?yàn)槲覀冊谑褂靡粋€(gè)聯(lián)調(diào)工具時(shí)，該工具預(yù)發(fā)布狀態(tài)下默認(rèn)開啟了 TDDL 的日志采集（盡管官方文檔中描述預(yù)發(fā)布狀態(tài)下默認(rèn)不會(huì)開啟 TDDL 采集，但實(shí)際上確實(shí)會(huì)進(jìn)行采集）。
在該工具打印日志時(shí)，會(huì)進(jìn)行數(shù)據(jù)脫敏操作，脫敏框架使用了 Google 的 re2j 進(jìn)行正則表達(dá)式匹配。
由于我的操作涉及到大量的 TDDL 操作，而默認(rèn)情況下會(huì)采集大量 TDDL 日志并進(jìn)行脫敏處理，這導(dǎo)致了較高的 CPU 消耗。
因此，通過在預(yù)發(fā)布環(huán)境中關(guān)閉對(duì) TDDL 的日志采集，可以有效解決這個(gè)問題。
這篇總結(jié)回顧了一次線上 CPU 飆高問題的排查過程，雖然問題最終解決起來并不復(fù)雜，但排查過程中卻有其獨(dú)特的教育意義。
之前經(jīng)驗(yàn)豐富的我按照慣例進(jìn)行了排查，初始階段并未發(fā)現(xiàn)明顯問題，錯(cuò)誤地將數(shù)據(jù)庫操作增加歸因于流量上升所致的正常情況。
通過多方查證（例如使用 arthas 查看序列獲取情況，以及通過數(shù)據(jù)庫查詢最新插入數(shù)據(jù)的主鍵 ID 等方法），最終確認(rèn)問題出在 TDDL 的序列初始化機(jī)制上。
解決了這個(gè)問題后，本以為問題徹底解決，卻又遭遇到 DP 采集 TDDL 日志導(dǎo)致 CPU 飆高的情況，最終再次解決問題后系統(tǒng)性能有了顯著提升。
因此，這個(gè)經(jīng)歷再次驗(yàn)證了“事出反常必有妖”，排查問題確實(shí)需要有耐心和系統(tǒng)性。
本文鏈接：http://www.tebozhan.com/showinfo-26-97280-0.html性能指標(biāo) | CPU飆高排查實(shí)戰(zhàn)
聲明：本網(wǎng)頁內(nèi)容旨在傳播知識(shí)，若有侵權(quán)等問題請及時(shí)與本網(wǎng)聯(lián)系，我們將在第一時(shí)間刪除處理。郵件：2376512515@qq.com
Copyright ? 2016-2023 天津谷騏科技有限公司 版權(quán)所有 sitemap.xml
違法及侵權(quán)請聯(lián)系：2376512515@qq.com 津ICP備18001702號(hào)
津公網(wǎng)安備 12010102000574號(hào)