一.常見的性能問題優(yōu)化的經(jīng)驗(yàn)分享

1.通過應(yīng)用日志定位思路

對(duì)于業(yè)務(wù)體量不大，QPS不高的服務(wù)來說，一般出現(xiàn)性能問題還是很好定位的，比如通過Prometheus等監(jiān)控平臺(tái)出現(xiàn)CPU或內(nèi)存使用率過高的時(shí)間點(diǎn)，看一下這個(gè)時(shí)間點(diǎn)附近的應(yīng)用日志，一般就可以看出其內(nèi)存溢出的地方了，偶爾報(bào)錯(cuò)的地方也并非就是引發(fā)性能問題的地方，因?yàn)閳?bào)錯(cuò)的地方只是壓垮駱駝的最后一根稻草，在此報(bào)錯(cuò)點(diǎn)之前的地方有出現(xiàn)耗費(fèi)性能的操作導(dǎo)致的。

有時(shí)候監(jiān)控趨勢圖顯示CPU彪生，但其實(shí)是因?yàn)镺OM引發(fā)的，要清晰的定位這些問題，這就得再借助下其他工具了，后文再介紹。

2.常見的性能問題

我們發(fā)現(xiàn)了日志報(bào)錯(cuò)點(diǎn)后，第一點(diǎn)就要去思考有沒有往內(nèi)存中加載大量數(shù)據(jù)的操作，比如Excel導(dǎo)出一次性加載大量數(shù)據(jù)而不采用分頁的、一次加載大量Redis緩存的、一次Select查詢大量Mysql數(shù)據(jù)的地方。

這些都是及其容易引發(fā)內(nèi)存溢出的地方，也是很多剛工作的同學(xué)經(jīng)常犯的錯(cuò)誤，他們?cè)陂_發(fā)環(huán)境數(shù)據(jù)量少時(shí)不會(huì)暴露此類問題，但是一旦發(fā)布生產(chǎn)環(huán)境，單表數(shù)據(jù)量到百萬數(shù)量級(jí)，此類問題就會(huì)出現(xiàn)，所以自己或問問同事有沒有寫過類似的操作或接口，從而快速定位。

以上都是憑借經(jīng)驗(yàn)判斷，如果開發(fā)者資歷尚淺或者問題隱藏較深，我們就需要借助一些工具來定位問題了。

二.CPU利用率過高問題定位

如果發(fā)現(xiàn)CPU利用率過高，比如達(dá)到了90%-100%時(shí)，我們可以直接登陸應(yīng)用服務(wù)器，通過以下步驟定位問題：

1.查看占用CPU高的線程

命令：top

PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND\
4380 root      20   0 9415956 2.350g  26772 S  90.3 41.4 426:14.30 java\
2083 root      20   0 1141656   9460   7044 S   0.7  0.2 130:19.20 Asiainfocwexam\
2038 root      20   0  495668   5880   4776 S   0.3  0.1 524:46.15 Asiainfocwmonit\
2093 root      20   0 1377548  10244   8324 S   0.3  0.2 514:56.84 Asiainfocwsvrd\
6708 root      20   0   27520   3236   2460 S   0.3  0.1   0:00.15 sshd\
21114 root      20   0  729064  18340   6856 S   0.3  0.3  39:46.81 bkmonitorbeat\
1 root      20   0   41284   2860   1940 S   0.0  0.0   0:15.97 systemd

我們可以看出第一個(gè)進(jìn)程PID：4380的CPU占用率過高，他就是我們的java服務(wù)，這里PID指的是進(jìn)程，我們需要根據(jù)進(jìn)程號(hào)，找到其占用CPU的線程。

命令：top -Hp 4380

注：

命令中H大寫，p小寫

• top：在終端實(shí)時(shí)顯示系統(tǒng)性能數(shù)據(jù)的命令。
• -H：該選項(xiàng)用于顯示所有線程的信息而不是僅顯示總體的信息。
• -p 4380：該選項(xiàng)指定要監(jiān)視的進(jìn)程的PID。在這里，4380是一個(gè)占位符，你可能會(huì)替換為實(shí)際的進(jìn)程PID。

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4558 root 20 0 9415956 2.333g 26772 S 92.9 41.1 160:56.84 java
4389 root 20 0 9415956 2.333g 26772 S 0.7 41.1 11:17.82 VM Thread
4473 root 20 0 9415956 2.333g 26772 S 0.7 41.1 4:38.15 redisson-netty-
4480 root 20 0 9415956 2.333g 26772 S 0.7 41.1 3:19.37 redisson-netty-

我們可以看到PID:4558的線程CPU使用率較高。

打印出問題線程的堆棧信息：

命令：printf '%x\n' 4558

將線程號(hào)轉(zhuǎn)為16進(jìn)制顯示，用于在堆棧中定位線程。

注：

• printf：是一個(gè)格式化輸出命令。
• '%x\n'：是格式控制字符串，表示將后面的參數(shù)按十六進(jìn)制格式輸出，并在末尾添加換行符。
• 4558：是要格式化輸出的整數(shù)。

[root]# printf ‘%x\n' 4558
11ce

命令 ：jstack 4380|grep -A 100 11ce

通過jstack打印進(jìn)程4380的堆棧信息，并只過濾出線程11ce的堆棧信息

命令含義：使用 jstack 來打印指定 Java 進(jìn)程（PID為4380）的線程堆棧信息，然后使用 grep 過濾輸出，查找包含特定字符串 “11ce” 的行，并打印該行及其后續(xù)100行的內(nèi)容。

注：

• jstack 4380：使用 jstack 命令獲取 Java 進(jìn)程 4380 的線程堆棧信息。
• |：管道符，將 jstack 的輸出傳遞給下一個(gè)命令。
• grep -A 200 11ce：使用 grep 過濾包含字符串 “11ce” 的行，同時(shí)打印每個(gè)匹配行的后續(xù)100行內(nèi)容（包括匹配行本身）。

"org.springframework.kafka.KafkaListenerEndpointContainer#0-0-C-1" #130 prio=5 os_prio=0 tid=0x00007f922eccd800 nid=0x11ce runnable [0x00007f91c80be000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x0000000088383dc0> (a sun.nio.ch.Util$3)
    - locked <0x0000000088383db0> (a java.util.Collections$UnmodifiableSet)
    - locked <0x0000000088383d68> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.kafka.common.network.Selector.select(Selector.java:869)
    at org.apache.kafka.common.network.Selector.poll(Selector.java:465)
    at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:563)
    at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:265)
    at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236)
    at org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1292)
    at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1233)
    at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1206)

其中第一行中 nid=0x11ce，此處就是我們上面16進(jìn)制線程號(hào)：11ce。所以此條堆棧對(duì)應(yīng)的代碼行數(shù)，即為耗費(fèi)CPU比較高的線程對(duì)應(yīng)的代碼(上面堆棧僅為示例)。

三.內(nèi)存利用率過高問題定位

1.內(nèi)存過高代碼定位

內(nèi)存過高和CPU過高一樣，都可以用上述方法定位，在下方%MEM列，即表示內(nèi)存占用率，找出對(duì)應(yīng)的PID，重復(fù)上面操作即可定位。

PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND\
4380 root      20   0 9415956 2.350g  26772 S  10.2 91.4 426:14.30 java\

2.設(shè)置java啟動(dòng)參數(shù)出現(xiàn)OOM自動(dòng)打印堆棧

在服務(wù)器上建立好路徑，比如：/usr/local/app/logs，然后當(dāng)服務(wù)發(fā)生OutOfMemoryError（OOM）內(nèi)存溢出時(shí)，會(huì)自動(dòng)打印堆棧信息到dump.hprof文件中，那時(shí)我們只需要分析此文件即可定位問題。

nohup java -XX:HeapDumpPath=/usr/local/app/logs/dump.hprof -XX:+HeapDumpOnOutOfMemoryError-jar /usr/local/app/test-web.jar  --spring.profiles.active=pro >/dev/null 2>&1 &

3.分析堆文件

在jdk安裝目錄下，jdk1.8.0_60\bin下，有jvisualvm.exe工具，打開這個(gè)工具，點(diǎn)擊文件->裝入->文件類型選擇hprof->選擇dump.hprof。

如下圖：

如果有OOM會(huì)顯示在概覽中，并且堆棧信息也打印了。

特別提醒：

OutOfMemoryError（OOM）的堆棧信息通常只顯示了導(dǎo)致內(nèi)存不足的最終操作，而不一定反映了問題的根本原因。

OOM 堆棧信息中的最上層可能只是觸發(fā)了 Java 虛擬機(jī)報(bào)告內(nèi)存不足的點(diǎn)，而不一定是導(dǎo)致內(nèi)存不足的真正原因。

即此工具分析結(jié)果只是壓死駱駝的最后一根稻草，并不一定是導(dǎo)致內(nèi)存溢出的原因，所以有時(shí)你還需要找到壓死駱駝的那塊大石頭，而不要只盯著這跟稻草優(yōu)化，比如有時(shí)候會(huì)顯示垃圾回收GC線程占用內(nèi)存過高，但GC可不是導(dǎo)致OOM的根因。

大多數(shù)情況下，jvisualvm定位到的問題就是OOM的原因，但不全是，所以你要明白原因。

四.使用阿里巴巴Arthas診斷工具

1.Arthas能做什么？

Arthas有很多強(qiáng)大功能，本文只針對(duì)CPU和內(nèi)存使用率過高的性能問題進(jìn)行講解，其他用法參考《官方文檔》拓展閱讀吧。

2.下載Arthas

如果服務(wù)器可以連接互聯(lián)網(wǎng)，可以直接使用下面的命令下載，如果不能聯(lián)網(wǎng)，可以下載jar包后上傳到服務(wù)器。

curl -O https://arthas.aliyun.com/arthas-boot.jar

3.啟動(dòng)Arthas

java -jar arthas-boot.jar

啟動(dòng)時(shí)，需要手動(dòng)選擇要監(jiān)控的java程序，如果只有一個(gè)，就輸入“1”，如果多個(gè)，輸入對(duì)應(yīng)的序號(hào)數(shù)字即可，

如圖：

4.定位占用資源多的線程堆棧

使用命令打印出占用CPU的線程堆棧，即可定位問題，然后就具體情況具體分析了，每個(gè)人遇到的問題都是不一樣的，這里只教學(xué)下排除問題的方法。

以下是幾個(gè)常用的命令：

①.查詢最忙的3個(gè)線程，采樣5000毫秒內(nèi)的堆棧信息：

thread -n 3 -i 5000

5000毫秒為采樣時(shí)間，如果不加-i 5000，那么默認(rèn)是采樣200毫秒，采樣時(shí)間過短的話往往不太準(zhǔn)確，因?yàn)椴蓸颖旧硪矔?huì)占用CPU性能，所以可以適當(dāng)延長一下

②.查詢當(dāng)前阻塞其他線程的線程：

thread -b

如果有堵塞的線程會(huì)打印出來，如果沒有則不會(huì)打印出結(jié)果。

比如一些kafka消費(fèi)類的線程，會(huì)一直處于堵塞狀態(tài)，這種其實(shí)也是正常的，并不是有堵塞的線程，就要去解決優(yōu)化。

我們要看看那些不應(yīng)該長時(shí)間堵塞的線程，為啥出現(xiàn)了堵塞。

注：thread命令使用參考《官方文檔-thread命令》

③.查看JVM信息，下面三個(gè)命令都可以：

jvm
sysprop
sysenv

如果忙碌線程中，長時(shí)間出現(xiàn)GC，那就開啟GC日志，

XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc.log

看看是否出現(xiàn)了Full GC，F(xiàn)ull GC日志示例：

2024-01-04T12:34:56.789-0500: [Full GC (System.gc()) [PSYoungGen: 0K->0K(5120K)] [ParOldGen: 4096K->4096K(10240K)] 4096K->4096K(15360K), [Metaspace: 1234K->1234K(8192K)], 0.0123456 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

如果出現(xiàn)了Full GC，那就用上文提到的jvisualvm.exe分析堆文件，找出占用內(nèi)存大的對(duì)象，并優(yōu)化。

總結(jié)

本文介紹了通過系統(tǒng)日志、java JDK工具、JVM參數(shù)、linux系統(tǒng)命令、Arthas診斷工具等方法，定位和解決線上CPU使用率過高、內(nèi)存使用率過高的方法，大家可以根據(jù)自己的環(huán)境靈活搭配使用上述方法，解決性能問題。

排查性能問題需要不斷的積累經(jīng)驗(yàn)的過程，新手可能感到無從下手，結(jié)合本文提到的工具，多嘗試、多總結(jié)，遇到性能問題不要僥幸，敬畏墨菲定律，不要想著重啟下就能解決，重啟大 法好，但不能提升你解決問題的能力。所以出現(xiàn)偶發(fā)的性能問題一定要及時(shí)去定位，不然就像定時(shí)炸彈一樣，在你下班時(shí)間引爆。

以上為個(gè)人經(jīng)驗(yàn)，希望能給大家一個(gè)參考，也希望大家多多支持腳本之家。

最新評(píng)論