线上问题诊断指南
內(nèi)容概要
- 診斷工具介紹
- 工具可用情況
- 偶現(xiàn)或已現(xiàn)問(wèn)題診斷思路
硬件資源觀測(cè)
top
top可以看整個(gè)系統(tǒng)cpu、內(nèi)存的使用情況，以及在各個(gè)進(jìn)程上的情況，如下：
$ top top - 13:14:07 up 2 days, 6:38, 0 users, load average: 1.65, 0.59, 0.27 Tasks: 17 total, 3 running, 14 sleeping, 0 stopped, 0 zombie %Cpu(s): 25.0 us, 0.0 sy, 0.0 ni, 74.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st MiB Mem : 12693.4 total, 12052.8 free, 271.6 used, 368.9 buff/cache MiB Swap: 4096.0 total, 4096.0 free, 0.0 used. 12171.8 avail MemPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND3174 work 20 0 3860 104 0 R 100.0 0.0 1:40.75 stress3175 work 20 0 3860 104 0 R 100.0 0.0 1:40.76 stress1 root 20 0 900 492 428 S 0.0 0.0 0:00.11 init10 work 20 0 10044 5140 3424 S 0.0 0.0 0:00.12 bash3051 work 20 0 6393208 204364 20116 S 0.0 1.6 0:07.51 java3173 work 20 0 3860 980 896 S 0.0 0.0 0:00.00 stress3176 work 20 0 10888 3932 3348 R 0.0 0.0 0:00.02 top- 第一行是系統(tǒng)概要：當(dāng)前時(shí)間，系統(tǒng)啟動(dòng)時(shí)長(zhǎng)，系統(tǒng)用戶數(shù)，系統(tǒng)負(fù)載1min/5min/15min
- 第二行是任務(wù)概要：總?cè)蝿?wù)數(shù)，正在運(yùn)行/睡眠/暫停/僵尸任務(wù)數(shù)
- 第三行cpu使用率：
????????us：非niced進(jìn)程花費(fèi)的cpu時(shí)間占比
????????sy：內(nèi)核進(jìn)程花費(fèi)的cpu時(shí)間占比
????????ni：niced進(jìn)程花費(fèi)的cpu時(shí)間占比
????????id：內(nèi)核空閑進(jìn)程花費(fèi)的cpu時(shí)間占比，一般來(lái)說(shuō)CPU是無(wú)法空閑的，CPU空閑著，指的是在運(yùn)行一個(gè)空閑程序的代碼。
????????wa：等待磁盤(pán)io完成花費(fèi)的cpu時(shí)間占比
????????hi：處理硬件中斷花費(fèi)的cpu時(shí)間占比
????????si：處理軟件中斷花費(fèi)的cpu時(shí)間占比
????????st：被其它虛擬機(jī)偷取的cpu時(shí)間占比
- 第四行是內(nèi)存使用率：
????????total：總內(nèi)存大小(MB)
????????free：空閑內(nèi)存大小(MB)
????????used：使用中的內(nèi)存大小(MB)
????????buff/cache：用于文件緩存與系統(tǒng)緩存的內(nèi)存大小(MB)
- 第五行是swap情況：
????????total：總swap文件大小
????????free：swap空閑大小
????????used：swap使用大小
????????avail Mem：可用內(nèi)存大小，和swap無(wú)關(guān)，約等于上一行中free+buff/cache
下面的列表顯示的就是各進(jìn)程情況了，除此之外，top還是個(gè)交互式命令，可直接在這個(gè)界面輸入指令使用其更多功能，如下：
| 指令 | 功能描述 |
| 1 | 查看1號(hào)cpu各核的cpu使用情況，類似mpstat |
| M | 進(jìn)程按內(nèi)存使用率倒序，同時(shí)按shift + m |
| P | 進(jìn)程按cpu使用率倒序，同時(shí)按shift + p |
| H | 查看線程情況，同時(shí)按shift + h |
| c | 查看進(jìn)程的完整命令行 |
| k | 殺死指定pid的進(jìn)程 |
| h | 查看幫助 |
| q | 退出top |
注意，這里面的指令，很多都是開(kāi)關(guān)式的，比如按1顯示cpu各核使用率，再按1就顯示整體cpu使用率了。
另外，如果你的電腦是8核的，top中進(jìn)程的CPU%最高可以到800%，初次看到這種現(xiàn)象時(shí)，還很容易嚇一跳呢！
iostat
iostat命令可以很方便的查看磁盤(pán)當(dāng)前的IO情況，如下：
$ iostat -xz 1 avg-cpu: %user %nice %system %iowait %steal %idle0.06 0.00 0.00 0.00 0.00 99.94Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 1.87 17854.96 3799.10 14930.26 42642.19 208548.03 26.82 7.10 0.37 1.04 0.20 0.28 522.73avg-cpu: %user %nice %system %iowait %steal %idle4.36 0.00 0.00 0.00 0.00 95.64Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util sda 0.00 0.00 0.00 606.00 0.00 2616.00 8.63 0.04 0.06 0.00 0.06 0.06 3.40注意，和vmstat一樣，第一次的輸出結(jié)果是歷史以來(lái)的統(tǒng)計(jì)值，一般可以忽略不計(jì)，如下：
- %util ：磁盤(pán)使用率，Linux認(rèn)為磁盤(pán)只能處理一個(gè)并發(fā)，但SSD或raid實(shí)際可以超過(guò)一個(gè)，所以100%也不一定代表滿載。
- avgqu-sz：磁盤(pán)任務(wù)隊(duì)列長(zhǎng)度，大于磁盤(pán)的并發(fā)任務(wù)數(shù)則磁盤(pán)處于飽和狀態(tài)。
- svctm：平均服務(wù)時(shí)間，不包括在磁盤(pán)隊(duì)列中的等待時(shí)間。
- r_await,w_await：讀寫(xiě)延遲時(shí)間(ms)，磁盤(pán)隊(duì)列等待時(shí)間+svctm，太大則磁盤(pán)飽和。
- r/s + w/s： 就是當(dāng)前的IOPS。
- avgrq-sz：就是當(dāng)前每秒平均吞吐量 單位是扇區(qū)（512b)。
iotop
iotop以進(jìn)程的角度查看io情況，如下：
# -P表示只看進(jìn)程整體的，不然iotop看的是每個(gè)線程的 # -o表示只看有io操作的進(jìn)程，不然iotop會(huì)列出所有進(jìn)程 $ sudo iotop -P -o Total DISK READ: 3.84 K/s | Total DISK WRITE: 138.97 M/s Current DISK READ: 3.84 K/s | Current DISK WRITE: 80.63 M/sPID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND737183 be/4 root 3.84 K/s 0.00 B/s 0.00 % 88.89 % [kworker/u256:1+flush-8:0]761496 be/4 work 0.00 B/s 138.96 M/s 0.00 % 79.09 % stress -d 1876 be/4 work 0.00 B/s 7.68 K/s 0.00 % 0.00 % java -Xms256m -Xmx1g -Xss1m -XX:MaxMetaspaceSize=1g ...可以看到整個(gè)磁盤(pán)的當(dāng)前讀寫(xiě)速率，以及各個(gè)進(jìn)程占用的比例。
iftop
iftop可以用來(lái)查看整個(gè)網(wǎng)卡以及各個(gè)連接的當(dāng)前網(wǎng)速，如下：
$ sudo iftop -B -nNP244KB 488KB 732KB 977KB 1.19MB └──────────────────────────────┴──────────────────────────────┴───────────────────────────────┴──────────────────────────────┴─────────────────────────────── 100.135.65.10:11111 => 100.135.95.10:29518 85.8KB 103KB 94.3KB<= 2.95KB 3.54KB 3.25KB 100.135.65.10:11111 => 100.135.95.9:35981 170KB 103KB 94.3KB<= 5.41KB 3.49KB 3.21KB 100.135.60.10:35172 => 100.135.24.54:3561 13.3KB 9.88KB 5.25KB<= 58.6KB 60.6KB 32.4KB 100.134.60.10:43240 => 100.134.24.55:3560 9.83KB 5.52KB 3.09KB<= 101KB 53.6KB 31.1KB 100.134.60.10:65932 => 100.154.24.55:3951 4.45KB 5.07KB 6.04KB<= 35.0KB 39.8KB 47.4KB 10.134.60.10:58990 => 10.134.24.5:80 22.0KB 19.2KB 22.5KB ───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── TX: cum: 10.9MB peak: 1.75MB rates: 611KB 438KB 557KB RX: 6.49MB 453KB 360KB 296KB 332KB TOTAL: 17.4MB 2.19MB 972KB 735KB 889KB另外，在nicstat、iftop命令不可用的情況下，也可以使用ifconfig + awk來(lái)查看網(wǎng)速，單位B/s，如下：
$ while sleep 1;do ifconfig;done|awk -v RS= 'match($0,/^(\w+):.*RX.*bytes ([0-9]+).*TX.*bytes ([0-9]+)/,a){eth=a[1];if(s[eth][1])print a[1],a[2]-s[eth][2],a[3]-s[eth][3];for(k in a)s[eth][k]=a[k]}'eth0 294873 353037 lo 2229 2229 eth0 613730 666086 lo 17981 17981 eth0 317336 544921 lo 5544 5544 eth0 237694 516947 lo 2256 2256全能觀測(cè)工具
sar
sar是一個(gè)幾乎全能的觀測(cè)工具，它可以觀測(cè)CPU、內(nèi)存、磁盤(pán)、網(wǎng)絡(luò)等等，不像上面的命令，只是側(cè)重某一方面，正因?yàn)樗绱藦?qiáng)大，掌握起來(lái)也要難得多，它的常見(jiàn)用法如下：
# cpu使用率 sar -u ALL 1 # 運(yùn)行隊(duì)列與負(fù)載 sar -q 1 # 中斷次數(shù) sar -I SUM 1 # 進(jìn)程創(chuàng)建次數(shù)與線程上下文切換次數(shù) sar -w 1 # 內(nèi)存使用、臟頁(yè)與slab sar -r ALL 1 # 缺頁(yè)與內(nèi)存頁(yè)掃描 sar -B 1 # 內(nèi)存swap使用 sar -S 1 1 sar -W 1 # 磁盤(pán)IOPS sar -dp 1 # 文件描述符與打開(kāi)終端數(shù) sar -v 1 1 # 網(wǎng)卡層使用率 sar -n DEV 1 # tcp層收包發(fā)包情況 sar -n TCP,ETCP 1 # socket使用情況 sar -n SOCK 1這只是列出了sar的一部分用法，實(shí)際上sar可以觀測(cè)到非常多的內(nèi)容，具體可以man sar查看。
dstat
bpytop
軟件資源觀測(cè)
線程
# 查看各java進(jìn)程的線程數(shù)量$ ps -o pid,nlwp -C javaPID NLWP2121 21# 查看java各線程CPU、內(nèi)存使用情況$ top -H -p `pgrep -n java`網(wǎng)絡(luò)連接
netstat是用來(lái)查看網(wǎng)絡(luò)連接信息的工具命令，具體來(lái)說(shuō)，像在編程語(yǔ)言中可以通過(guò)創(chuàng)建socket來(lái)建立網(wǎng)絡(luò)連接，而netstat就是用來(lái)查看這些socket信息的，如下：
# 查看所有的socket，-n代表不解析ip為主機(jī)名，-a表示all所有，-t代表tcp$ netstat -nat# 顯示各狀態(tài)socket數(shù)量，TIME_WAIT與CLOSE_WAIT數(shù)量太多，一般都不是好事情$ netstat -nat | awk '/tcp/{print $6}'|sort|uniq -c21 ESTABLISHED3 TIME_WAIT3 CLOSE_WAIT2 LISTEN# 查看LISTEN狀態(tài)的socket，-l代表只顯示LISTEN狀態(tài)的$ netstat -nltActive Internet connections (only servers)Proto Recv-Q Send-Q Local Address Foreign Address Statetcp 0 0 0.0.0.0:8888 0.0.0.0:* LISTENtcp6 0 0 :::8888 :::* LISTEN# 查看進(jìn)程867的socket數(shù)量，-p顯示出創(chuàng)建網(wǎng)絡(luò)連接的進(jìn)程號(hào)$ netstat -natp|grep -w 867 -c2# 找到監(jiān)聽(tīng)在8888端口的進(jìn)程$ netstat -nltp|grep -w 8888tcp 0 0 0.0.0.0:8888 0.0.0.0:* LISTEN 867/ncattcp6 0 0 :::8888 :::* LISTEN 867/ncatjvm觀測(cè)工具
jstack
jstack是JVM下的線程剖析工具，可以打印出當(dāng)前時(shí)刻各線程的調(diào)用棧，這樣就可以了解到j(luò)vm中各線程都在干什么了，如下：
$ jstack 3051 2021-11-07 21:55:06 Full thread dump OpenJDK 64-Bit Server VM (11.0.12+7 mixed mode):Threads class SMR info: _java_thread_list=0x00007f3380001f00, length=10, elements={ 0x00007f33cc027800, 0x00007f33cc22f800, 0x00007f33cc233800, 0x00007f33cc24b800, 0x00007f33cc24d800, 0x00007f33cc24f800, 0x00007f33cc251800, 0x00007f33cc253800, 0x00007f33cc303000, 0x00007f3380001000 }"main" 1 prio=5 os_prio=0 cpu=2188.06ms elapsed=1240974.04s tid=0x00007f33cc027800 nid=0xbec runnable [0x00007f33d1b68000]java.lang.Thread.State: RUNNABLEat java.io.FileInputStream.readBytes(java.base@11.0.12/Native Method)at java.io.FileInputStream.read(java.base@11.0.12/FileInputStream.java:279)at java.io.BufferedInputStream.read1(java.base@11.0.12/BufferedInputStream.java:290)at java.io.BufferedInputStream.read(java.base@11.0.12/BufferedInputStream.java:351)- locked <0x00000007423a5ba8> (a java.io.BufferedInputStream)at sun.nio.cs.StreamDecoder.readBytes(java.base@11.0.12/StreamDecoder.java:284)at sun.nio.cs.StreamDecoder.implRead(java.base@11.0.12/StreamDecoder.java:326)at sun.nio.cs.StreamDecoder.read(java.base@11.0.12/StreamDecoder.java:178)- locked <0x0000000745ad1cf0> (a java.io.InputStreamReader)at java.io.InputStreamReader.read(java.base@11.0.12/InputStreamReader.java:181)at java.io.Reader.read(java.base@11.0.12/Reader.java:189)at java.util.Scanner.readInput(java.base@11.0.12/Scanner.java:882)at java.util.Scanner.findWithinHorizon(java.base@11.0.12/Scanner.java:1796)at java.util.Scanner.nextLine(java.base@11.0.12/Scanner.java:1649)at com.example.clientserver.ClientServerApplication.getDemo(ClientServerApplication.java:57)at com.example.clientserver.ClientServerApplication.run(ClientServerApplication.java:40)at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:804)at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:788)at org.springframework.boot.SpringApplication.run(SpringApplication.java:333)at org.springframework.boot.SpringApplication.run(SpringApplication.java:1309)at org.springframework.boot.SpringApplication.run(SpringApplication.java:1298)at com.example.clientserver.ClientServerApplication.main(ClientServerApplication.java:27)at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.12/Native Method)at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.12/NativeMethodAccessorImpl.java:62)at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.12/DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(java.base@11.0.12/Method.java:566)at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)at org.springframework.boot.loader.Launcher.launch(Launcher.java:107)at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)"Reference Handler" 2 daemon prio=10 os_prio=0 cpu=2.76ms elapsed=1240973.97s tid=0x00007f33cc22f800 nid=0xbf3 waiting on condition [0x00007f33a820a000]java.lang.Thread.State: RUNNABLEat java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.12/Native Method)at java.lang.ref.Reference.processPendingReferences(java.base@11.0.12/Reference.java:241)at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.12/Reference.java:213)實(shí)例：找占用CPU較高問(wèn)題代碼
如果你發(fā)現(xiàn)你的java進(jìn)程CPU占用一直都很高，可以用如下方法找到問(wèn)題代碼：
1，找出占用cpu的線程號(hào)pid
# -H表示看線程，其中312是java進(jìn)程的pid $ top -H -p 3122，轉(zhuǎn)換線程號(hào)為16進(jìn)制
# 其中62是從top中獲取的高cpu的線程pid $ printf "%x" 314 13a3，獲取進(jìn)程中所有線程棧，提取對(duì)應(yīng)高cpu線程棧
$ jstack 312 | awk -v RS= '/0x13a/'通過(guò)這種方法，可以很容易找到類似大循環(huán)或死循環(huán)之類性能極差的代碼。
實(shí)例：棧統(tǒng)計(jì)
一般來(lái)說(shuō)，jstack配合top只能定位類似死循環(huán)這種非常嚴(yán)重的性能問(wèn)題，由于cpu速度太快了，對(duì)于性能稍差但又不非常差的代碼，單次jstack很難從線程棧中捕捉到問(wèn)題代碼。
因?yàn)樾阅苌圆畹拇a可能只會(huì)比好代碼多耗1ms的cpu時(shí)間，但這1ms就比我們的手速快多了，當(dāng)執(zhí)行jstack時(shí)線程早已執(zhí)行到非問(wèn)題代碼了。
既然手動(dòng)執(zhí)行jstack不行，那就讓腳本來(lái)，快速執(zhí)行jstack多次，雖然問(wèn)題代碼對(duì)于人來(lái)說(shuō)執(zhí)行太快，但對(duì)于正常代碼來(lái)說(shuō)，它還是慢一些的，因此當(dāng)我快速捕捉多次線程棧時(shí)，問(wèn)題代碼出現(xiàn)的次數(shù)肯定比正常代碼出現(xiàn)的次數(shù)要多。
# 每0.2s執(zhí)行一次jstack，并將線程棧數(shù)據(jù)保存到j(luò)stacklog.log $ while sleep 0.2;do \ pid=$(pgrep -n java); \ [[ $pid ]] && jstack $pid; \ done > jstacklog.log$ wc -l jstacklog.log 291121 jstacklog.log抓了這么多線程棧，如何分析呢？我們可以使用linux中的文本命令來(lái)處理，按線程棧分組計(jì)數(shù)即可，如下：
$ cat jstacklog.log \ |sed -E -e 's/0x[0-9a-z]+/0x00/g' -e '/^"/ s/[0-9]+/n/g' \ |awk -v RS="" 'gsub(/\n/,"\\n",$0)||1' \ |sort|uniq -c|sort -nr \ |sed 's/$/\n/;s/\\n/\n/g' \ |less出現(xiàn)次數(shù)最多的線程棧，大概率就是性能不佳或阻塞住的代碼，上圖中com.example.demo.web.controller.TestController.select方法棧抓取到2053次，是因?yàn)槲乙恢痹趬簻y(cè)這一個(gè)接口，所以它被抓出來(lái)最多。
實(shí)例：火焰圖
可以發(fā)現(xiàn)，用文本命令分析線程棧并不直觀，好在性能優(yōu)化大師Brendan Gregg發(fā)明了火焰圖，并開(kāi)發(fā)了一套火焰圖生成工具。
工具下載地址：https://github.com/brendangregg/FlameGraph
將jstack抓取的一批線程棧，生成一個(gè)火焰圖，如下：
$ cat jstacklog.log \| ./FlameGraph/stackcollapse-jstack.pl --no-include-tname \| ./FlameGraph/flamegraph.pl --cp > jstacklog.svg如上，生成的火焰圖是svg文件，使用瀏覽器打開(kāi)即可，在火焰圖中，顏色并沒(méi)有實(shí)際含義，它將相同的線程棧聚合在一起顯示，因此，圖中越寬的棧表示此棧在運(yùn)行過(guò)程中，被抓取到的次數(shù)越多，也是我們需要重點(diǎn)優(yōu)化的地方。
jmap
jmap是JVM下的內(nèi)存剖析工具，用來(lái)分析或?qū)С鯦VM堆數(shù)據(jù)，如下：
# 查看對(duì)象分布直方圖，其中3051是java進(jìn)程的pid $ jmap -histo:live 3051 | head -n20num instances bytes class name (module) -------------------------------------------------------1: 19462 1184576 [B (java.base@11.0.12)2: 3955 469920 java.lang.Class (java.base@11.0.12)3: 18032 432768 java.lang.String (java.base@11.0.12)4: 11672 373504 java.util.concurrent.ConcurrentHashMap$Node (java.base@11.0.12)5: 3131 198592 [Ljava.lang.Object; (java.base@11.0.12)6: 5708 182656 java.util.HashMap$Node (java.base@11.0.12)7: 1606 155728 [I (java.base@11.0.12)8: 160 133376 [Ljava.util.concurrent.ConcurrentHashMap$Node; (java.base@11.0.12)9: 1041 106328 [Ljava.util.HashMap$Node; (java.base@11.0.12)10: 6216 99456 java.lang.Object (java.base@11.0.12)11: 1477 70896 sun.util.locale.LocaleObjectCache$CacheEntry (java.base@11.0.12)12: 1403 56120 java.util.LinkedHashMap$Entry (java.base@11.0.12)13: 1322 52880 java.lang.ref.SoftReference (java.base@11.0.12)14: 583 51304 java.lang.reflect.Method (java.base@11.0.12)15: 999 47952 java.lang.invoke.MemberName (java.base@11.0.12)16: 29 42624 [C (java.base@11.0.12)17: 743 41608 java.util.LinkedHashMap (java.base@11.0.12)18: 877 35080 java.lang.invoke.MethodType (java.base@11.0.12)也可以直接將整個(gè)堆內(nèi)存轉(zhuǎn)儲(chǔ)為文件，如下：
$ jmap -dump:format=b,file=heap.hprof 3456 Heap dump file created$ ls *.hprof heap.hprof堆轉(zhuǎn)儲(chǔ)文件是二進(jìn)制文件，沒(méi)法直接查看，一般是配合mat(Memory Analysis Tool)等堆可視化工具來(lái)進(jìn)行分析，如下：
mat打開(kāi)hprof文件后，會(huì)看下如下一個(gè)概要界面。
點(diǎn)擊Histogram可以按類維度查詢內(nèi)存占用大小
點(diǎn)擊Dominator Tree可以看到各對(duì)象總大小(Retained Heap，包含引用的子對(duì)象)，以及所占內(nèi)存比例，可以看到一個(gè)ArrayList對(duì)象占用99.31%，看來(lái)是個(gè)bug，找到創(chuàng)建ArrayList的代碼，修改即可。
可以看到，使用jmap+mat很容易分析內(nèi)存泄露bug，但需要注意的是，jmap執(zhí)行時(shí)會(huì)讓jvm暫停，對(duì)于高并發(fā)的服務(wù)，最好先將問(wèn)題節(jié)點(diǎn)摘除流量后再操作。
另外，可以在jvm上添加參數(shù)-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=./dump/，使得在發(fā)生內(nèi)存溢出時(shí)，自動(dòng)生成堆轉(zhuǎn)儲(chǔ)文件到dump目錄。
mat下載地址：http://www.eclipse.org/mat/
arthas
arthas是java下的一款動(dòng)態(tài)追蹤工具，可以觀測(cè)到j(luò)ava方法的調(diào)用參數(shù)、返回值等，除此之外，還提供了很多實(shí)用功能，如反編譯、線程剖析、堆內(nèi)存轉(zhuǎn)儲(chǔ)、火焰圖等。
下載與使用
# 下載arthas $ wget https://arthas.aliyun.com/download/3.4.6?mirror=aliyun -O arthas-packaging-3.4.6-bin.zip# 解壓 $ unzip arthas-packaging-3.4.6-bin.zip -d arthas && cd arthas/# 進(jìn)入arthas命令交互界面 $ java -jar arthas-boot.jar `pgrep -n java` [INFO] arthas-boot version: 3.4.6 [INFO] arthas home: /home/work/arthas [INFO] Try to attach process 3368243 [INFO] Attach process 3368243 success. [INFO] arthas-client connect 127.0.0.1 3658,---. ,------. ,--------.,--. ,--. ,---. ,---./ O \ | .--. ''--. .--'| '--' | / O \ ' .-' | .-. || '--'.' | | | .--. || .-. |`. `-. | | | || |\ \ | | | | | || | | |.-' | `--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'wiki https://arthas.aliyun.com/doc tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html version 3.4.6 pid 3368243 time 2021-11-13 13:35:49# help可查看arthas提供了哪些命令 [arthas@3368243]$ help # help watch可查看watch命令具體用法 [arthas@3368243]$ help watchwatch、trace與stack
在arthas中，使用watch、trace、stack命令可以觀測(cè)方法調(diào)用情況，如下：
# watch觀測(cè)執(zhí)行的查詢SQL，-x 3指定對(duì)象展開(kāi)層級(jí) [arthas@3368243]$ watch org.apache.ibatis.executor.statement.PreparedStatementHandler parameterize '{target.boundSql.sql,target.boundSql.parameterObject}' -x 3 method=org.apache.ibatis.executor.statement.PreparedStatementHandler.parameterize location=AtExit ts=2021-11-13 14:50:34; [cost=0.071342ms] result=@ArrayList[@String[select id,log_info,create_time,update_time,add_time from app_log where id=?],@ParamMap[@String[id]:@Long[41115],@String[param1]:@Long[41115],], ]# watch觀測(cè)耗時(shí)超過(guò)200ms的SQL [arthas@3368243]$ watch com.mysql.jdbc.PreparedStatement execute '{target.toString()}' 'target.originalSql.contains("select") && #cost > 200' -x 2 Press Q or Ctrl+C to abort. Affect(class count: 3 , method count: 1) cost in 123 ms, listenerId: 25 method=com.mysql.jdbc.PreparedStatement.execute location=AtExit ts=2021-11-13 14:58:42; [cost=1001.558851ms] result=@ArrayList[@String[com.mysql.jdbc.PreparedStatement@6283cfe6: select count(*) from app_log], ]# trace追蹤方法耗時(shí)，層層追蹤，就可找到耗時(shí)根因，--skipJDKMethod false顯示jdk方法耗時(shí)，默認(rèn)不顯示 [arthas@3368243]$ trace com.mysql.jdbc.PreparedStatement execute 'target.originalSql.contains("select") && #cost > 200' --skipJDKMethod false Press Q or Ctrl+C to abort. Affect(class count: 3 , method count: 1) cost in 191 ms, listenerId: 26 ---ts=2021-11-13 15:00:40;thread_name=http-nio-8080-exec-47;id=76;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@5a2d131d---[1001.465544ms] com.mysql.jdbc.PreparedStatement:execute()+---[0.022119ms] com.mysql.jdbc.PreparedStatement:checkClosed() #1274+---[0.016294ms] com.mysql.jdbc.MySQLConnection:getConnectionMutex() #57+---[0.017862ms] com.mysql.jdbc.PreparedStatement:checkReadOnlySafeStatement() #1278+---[0.008996ms] com.mysql.jdbc.PreparedStatement:createStreamingResultSet() #1294+---[0.010783ms] com.mysql.jdbc.PreparedStatement:clearWarnings() #1296+---[0.017843ms] com.mysql.jdbc.PreparedStatement:fillSendPacket() #1316+---[0.008543ms] com.mysql.jdbc.MySQLConnection:getCatalog() #1320+---[0.009293ms] java.lang.String:equals() #57+---[0.008824ms] com.mysql.jdbc.MySQLConnection:getCacheResultSetMetadata() #1328+---[0.009892ms] com.mysql.jdbc.MySQLConnection:useMaxRows() #1354+---[1001.055229ms] com.mysql.jdbc.PreparedStatement:executeInternal() #1379+---[0.02076ms] com.mysql.jdbc.ResultSetInternalMethods:reallyResult() #1388+---[0.011517ms] com.mysql.jdbc.MySQLConnection:getCacheResultSetMetadata() #57+---[0.00842ms] com.mysql.jdbc.ResultSetInternalMethods:getUpdateID() #1404---[0.008112ms] com.mysql.jdbc.ResultSetInternalMethods:reallyResult() #1409# stack追蹤方法調(diào)用棧，找到耗時(shí)SQL來(lái)源 [arthas@3368243]$ stack com.mysql.jdbc.PreparedStatement execute 'target.originalSql.contains("select") && #cost > 200' Press Q or Ctrl+C to abort. Affect(class count: 3 , method count: 1) cost in 138 ms, listenerId: 27 ts=2021-11-13 15:01:55;thread_name=http-nio-8080-exec-5;id=2d;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@5a2d131d@com.mysql.jdbc.PreparedStatement.execute()at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:493)at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:63)at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:326)at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:136)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)at sun.reflect.GeneratedMethodAccessor75.invoke(null:-1)at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)at java.lang.reflect.Method.invoke(Method.java:498)at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)at com.sun.proxy.$Proxy113.selectOne(null:-1)at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:83)at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)at com.sun.proxy.$Proxy119.selectCost(null:-1)at com.demo.example.web.controller.TestController.select(TestController.java:57)可以看到watch、trace、stack命令中都可以指定條件表達(dá)式，只要滿足ognl表達(dá)式語(yǔ)法即可，ognl完整語(yǔ)法很復(fù)雜，如下是一些經(jīng)常使用的：
ognl
通過(guò)ognl命令，可直接查看靜態(tài)變量的值，如下：
# 調(diào)用System.getProperty靜態(tài)函數(shù)，查看jvm默認(rèn)字符編碼 [arthas@3368243]$ ognl '@System@getProperty("file.encoding")' @String[UTF-8]# 找到springboot類加載器 [arthas@3368243]$ classloader -t +-BootstrapClassLoader +-sun.misc.Launcher$ExtClassLoader@492691d7+-sun.misc.Launcher$AppClassLoader@764c12b6+-org.springframework.boot.loader.LaunchedURLClassLoader@4361bd48# 獲取springboot中所有的beanName，-c指定springboot的classloader的hash值 # 一般Spring項(xiàng)目，都會(huì)定義一個(gè)SpringUtil的，用于獲取bean容器ApplicationContext [arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.beanFactory.beanDefinitionNames' @String[][@String[org.springframework.context.annotation.internalConfigurationAnnotationProcessor],@String[org.springframework.context.annotation.internalAutowiredAnnotationProcessor],@String[org.springframework.context.annotation.internalCommonAnnotationProcessor],@String[testController],@String[apiController],@String[loginService],... ]# 獲取springboot配置，如server.port是配置http服務(wù)端口的 [arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.getEnvironment().getProperty("server.port")' @String[8080]# 查看server.port定義在哪個(gè)配置文件中 # 可以很容易看到，server.port定義在application-web.yml [arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.environment.propertySources.propertySourceList.{? containsProperty("server.port")}' @ArrayList[@ConfigurationPropertySourcesPropertySource[ConfigurationPropertySourcesPropertySource {name='configurationProperties'}],@OriginTrackedMapPropertySource[OriginTrackedMapPropertySource {name='applicationConfig: [classpath:/application-web.yml]'}], ]# 調(diào)用springboot中bean的方法，獲取返回值 [arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.getBean("demoMapper").queryOne(12)' -x 2 @ArrayList[@HashMap[@String[update_time]:@Timestamp[2021-11-09 18:38:13,000],@String[create_time]:@Timestamp[2021-04-17 15:52:55,000],@String[log_info]:@String[TbTRNsh2SixuFrkYLTeb25a6zklEZj0uWANKRMe],@String[id]:@Long[12],@String[add_time]:@Integer[61],], ]# 查看springboot自帶tomcat的線程池的情況 [arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.webServer.tomcat.server.services[0].connectors[0].protocolHandler.endpoint.executor' @ThreadPoolExecutor[sm=@StringManager[org.apache.tomcat.util.res.StringManager@16886f49],submittedCount=@AtomicInteger[1],threadRenewalDelay=@Long[1000],workQueue=@TaskQueue[isEmpty=true;size=0],mainLock=@ReentrantLock[java.util.concurrent.locks.ReentrantLock@69e9cf90[Unlocked]],workers=@HashSet[isEmpty=false;size=10],largestPoolSize=@Integer[49],completedTaskCount=@Long[10176],threadFactory=@TaskThreadFactory[org.apache.tomcat.util.threads.TaskThreadFactory@63c03c4f],handler=@RejectHandler[org.apache.tomcat.util.threads.ThreadPoolExecutor$RejectHandler@3667e559],keepAliveTime=@Long[60000000000],allowCoreThreadTimeOut=@Boolean[false],corePoolSize=@Integer[10],maximumPoolSize=@Integer[8000], ]其它命令
arthas還提供了jvm大盤(pán)、線程剖析、堆轉(zhuǎn)儲(chǔ)、反編譯、火焰圖等功能，如下：
# 顯示耗cpu較多的前4個(gè)線程 [arthas@3368243]$ thread -n 4 "C2 CompilerThread0" [Internal] cpuUsage=8.13% deltaTime=16ms time=46159ms"C2 CompilerThread1" [Internal] cpuUsage=4.2% deltaTime=8ms time=47311ms"C1 CompilerThread2" [Internal] cpuUsage=3.06% deltaTime=6ms time=17402ms"http-nio-8080-exec-40" Id=111 cpuUsage=1.29% deltaTime=2ms time=624ms RUNNABLE (in native)at java.net.SocketInputStream.socketRead0(Native Method)...at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4113)at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570)at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2818)...at com.demo.example.web.controller.TestController.select(TestController.java:57)# 堆轉(zhuǎn)儲(chǔ) [arthas@3368243]$ heapdump Dumping heap to /tmp/heapdump2021-11-13-15-117226383240040009563.hprof ... Heap dump file created# cpu火焰圖，容器環(huán)境下profiler start可能用不了，可用profiler start -e itimer替代 [arthas@3368243]$ profiler start Started [cpu] profiling [arthas@3368243]$ profiler stop OK profiler output file: /home/work/app/arthas-output/20211113-151208.svg# dashboard就類似Linux下的top一樣，可看jvm線程、堆內(nèi)存的整體情況 [arthas@3368243]$ dashboard# jvm就類似Linux下的ps一樣，可以看jvm進(jìn)程的一些基本信息，如：jvm參數(shù)、類加載、線程數(shù)、打開(kāi)文件描述符數(shù)等 [arthas@3368243]$ jvm# 反編譯 [arthas@3368243]$ jad com.demo.example.web.controller.TestController可見(jiàn)，arthas已經(jīng)不是一個(gè)單純的動(dòng)態(tài)追蹤工具了，它把jvm下常用的診斷功能幾乎全囊括了。
相關(guān)項(xiàng)目地址：
https://arthas.aliyun.com/doc/index.html
https://github.com/jvm-profiling-tools/async-profiler
系統(tǒng)調(diào)用觀測(cè)
strace
strace是Linux中用來(lái)觀測(cè)系統(tǒng)調(diào)用的工具，學(xué)過(guò)操作系統(tǒng)原理都知道，操作系統(tǒng)向應(yīng)用程序暴露了一批系統(tǒng)調(diào)用接口，應(yīng)用程序只能通過(guò)這些系統(tǒng)調(diào)用接口來(lái)訪問(wèn)操作系統(tǒng)，比如申請(qǐng)內(nèi)存、文件或網(wǎng)絡(luò)io操作等。
用法如下：
# -T 打印系統(tǒng)調(diào)用花費(fèi)的時(shí)間 # -tt 打印系統(tǒng)調(diào)用的時(shí)間點(diǎn) # -s 輸出的最大長(zhǎng)度，默認(rèn)32，對(duì)于調(diào)用參數(shù)較長(zhǎng)的場(chǎng)景，建議加大 # -f 是否追蹤fork出來(lái)子進(jìn)程的系統(tǒng)調(diào)用，由于服務(wù)端服務(wù)普通使用線程池，建議加上 # -p 指定追蹤的進(jìn)程pid # -o 指定追蹤日志輸出到哪個(gè)文件，不指定則直接輸出到終端 $ strace -T -tt -f -s 200 -p 87 -o strace.log實(shí)例：抓取實(shí)際發(fā)送的SQL
有些時(shí)候，我們會(huì)發(fā)現(xiàn)代碼中完全沒(méi)問(wèn)題的SQL，卻查不到數(shù)據(jù)，這極有可能是由于項(xiàng)目中一些底層框架改寫(xiě)了SQL，導(dǎo)致真實(shí)發(fā)送的SQL與代碼中的SQL不一樣。
遇到這種情況，先別急著扒底層框架代碼，那樣會(huì)比較花時(shí)間，畢竟程序員的時(shí)間很寶貴，不然要加更多班的，怎么快速確認(rèn)是不是這個(gè)原因呢？
有兩種方法，第一種是使用wireshark抓包，第二種就是本篇介紹的strace了，由于程序必然要通過(guò)網(wǎng)絡(luò)io相關(guān)的系統(tǒng)調(diào)用，將SQL命令發(fā)送到數(shù)據(jù)庫(kù)，因此我們只需要用strace追蹤所有系統(tǒng)調(diào)用，然后grep出發(fā)送SQL的系統(tǒng)調(diào)用即可，如下：
$ strace -T -tt -f -s 200 -p 52 |& tee strace.log從圖中可以清晰看到，mysql的jdbc驅(qū)動(dòng)是通過(guò)sendto系統(tǒng)調(diào)用來(lái)發(fā)送SQL，通過(guò)recvfrom來(lái)獲取返回結(jié)果，可以發(fā)現(xiàn)，由于SQL是字符串，strace自動(dòng)幫我們識(shí)別出來(lái)了，而返回結(jié)果因?yàn)槭嵌M(jìn)制的，就不容易識(shí)別了，需要非常熟悉mysql協(xié)議才行。
另外，從上面其實(shí)也很容易看出SQL執(zhí)行耗時(shí)，計(jì)算相同線程號(hào)的sendto與recvfrom之間的時(shí)間差即可。
內(nèi)核觀測(cè)工具
perf
perf是Linux官方維護(hù)的性能分析工具，它可以觀測(cè)很多非常細(xì)非常硬核的指標(biāo)，如IPC，cpu緩存命中率等，如下：
# ubuntu安裝perf，包名和內(nèi)核版本相關(guān)，可以直接輸入perf命令會(huì)給出安裝提示 sudo apt install linux-tools-5.4.0-74-generic linux-cloud-tools-5.4.0-74-generic# cpu的上下文切換、cpu遷移、IPC、分支預(yù)測(cè) sudo perf stat -a sleep 5 # cpu的IPC與緩存命中率 sudo perf stat -e cycles,instructions,cache-references,cache-misses,bus-cycles -a sleep 10 # cpu的1級(jí)數(shù)據(jù)緩存命中率 sudo perf stat -e L1-dcache-loads,L1-dcache-load-misses,L1-dcache-stores -a sleep 10 # 頁(yè)表緩存TLB命中率 sudo perf stat -e dTLB-loads,dTLB-load-misses,dTLB-prefetch-misses -a sleep 10 # cpu的最后一級(jí)緩存命中率 sudo perf stat -e LLC-loads,LLC-load-misses,LLC-stores,LLC-prefetches -a sleep 10# Count system calls by type for the specified PID, until Ctrl-C: sudo perf stat -e 'syscalls:sys_enter_*' -p PID -I1000 2>&1 | awk '$2 != 0' # Count system calls by type for the entire system, for 5 seconds: sudo perf stat -e 'syscalls:sys_enter_*' -a sleep 5 2>&1| awk '$1 != 0' # Count syscalls per-second system-wide: sudo perf stat -e raw_syscalls:sys_enter -I 1000 -aoncpu火焰圖
當(dāng)然，它也可以用來(lái)抓取線程棧，并生成火焰圖，如下：
# 抓取60s的線程棧，其中1892是mysql的進(jìn)程pid $ sudo perf record -F 99 -p 1892 -g sleep 60 [ perf record: Woken up 5 times to write data ] [ perf record: Captured and wrote 1.509 MB perf.data (6938 samples) ]# 生成火焰圖 $ sudo perf script \| ./FlameGraph/stackcollapse-perf.pl \| ./FlameGraph/flamegraph.pl > mysqld_flamegraph.svg如上所示，使用perf生成的mysql的火焰圖，perf抓取線程棧相比jstack的優(yōu)點(diǎn)是，抓取精度比jstack更高，運(yùn)行開(kāi)銷比jstack更小，并且還可以抓到Linux內(nèi)核調(diào)用棧！
注：perf抓取線程棧，是順著cpu上的棧寄存器找到當(dāng)前線程的調(diào)用棧的，因此它只能抓到當(dāng)前正在cpu上運(yùn)行線程的線程棧，因此通過(guò)perf可以非常容易做oncpu分析，分析high cpu問(wèn)題。offcpu火焰圖
線程在運(yùn)行的過(guò)程中，要么在CPU上執(zhí)行，要么被鎖或io操作阻塞，從而離開(kāi)CPU進(jìn)去睡眠狀態(tài)，待被解鎖或io操作完成，線程會(huì)被喚醒而變成運(yùn)行態(tài)。
如下：
當(dāng)線程在cpu上運(yùn)行時(shí)，我們稱其為oncpu，當(dāng)線程阻塞而離開(kāi)cpu后，稱其為offcpu。
如果當(dāng)線程在睡眠之前記錄一下當(dāng)前時(shí)間，然后被喚醒時(shí)記錄當(dāng)前線程棧與阻塞時(shí)間，再使用FlameGraph工具將線程棧繪制成一張火焰圖，這樣我們就得到了一張offcpu火焰圖，火焰圖寬的部分就是線程阻塞較多的點(diǎn)了，這就需要再介紹一下bcc工具了。
bcc
bcc是使用Linux ebpf機(jī)制實(shí)現(xiàn)的一套工具集，包含非常多的底層分析工具，如查看文件緩存命中率，tcp重傳情況，mysql慢查詢等等。
它還可以做offcpu分析，生成offcpu火焰圖，如下：
# ubuntu安裝bcc工具集 $ sudo apt install bpfcc-tools # 使用root身份進(jìn)入bash $ sudo bash # 獲取jvm函數(shù)符號(hào)信息 $ ./FlameGraph/jmaps # 抓取offcpu線程棧30s，83101是mysqld的進(jìn)程pid $ offcputime-bpfcc -df -p 83101 30 > offcpu_stack.out # 生成offcpu火焰圖 $ cat offcpu_stack.out \| sed 's/;::/:::/g' \| ./FlameGraph/flamegraph.pl --color=io --title="Off-CPU Time Flame Graph" --countname=us > offcpu_stack.svg如上圖，我繪制了一張mysql的offcpu火焰圖，可以發(fā)現(xiàn)大多數(shù)線程的offcpu都是由鎖引起的，另外，offcpu火焰圖與oncpu火焰圖稍有不同，oncpu火焰圖寬度代表線程棧出現(xiàn)次數(shù)，而offcpu火焰圖寬度代表線程棧阻塞時(shí)間。
bcc項(xiàng)目地址：https://github.com/iovisor/bcc
bpftrace
arthas只能追蹤java程序，對(duì)于原生程序(如MySQL)就無(wú)能為力了，好在Linux生態(tài)提供了大量的機(jī)制以及配套工具，可用于追蹤原生程序的調(diào)用，如perf、bpftrace、systemtap等，由于bpftrace使用難度較小，本篇主要介紹它的用法。
bpftrace是基于ebpf技術(shù)實(shí)現(xiàn)的動(dòng)態(tài)追蹤工具，它對(duì)ebpf技術(shù)進(jìn)行封裝，實(shí)現(xiàn)了一種腳本語(yǔ)言，就像上面介紹的arthas基于ognl一樣，它實(shí)現(xiàn)的腳本語(yǔ)言類似于awk，封裝了常見(jiàn)語(yǔ)句塊，并提供內(nèi)置變量與內(nèi)置函數(shù)，如下：
$ sudo bpftrace -e 'BEGIN { printf("Hello, World!\n"); } ' Attaching 1 probe... Hello, World!實(shí)例：在調(diào)用端追蹤慢SQL
前面我們用strace追蹤過(guò)mysql的jdbc驅(qū)動(dòng)，它使用sendto與recvfrom系統(tǒng)調(diào)用來(lái)與mysql服務(wù)器通信，因此，我們?cè)趕endto調(diào)用時(shí)，計(jì)下時(shí)間點(diǎn)，然后在recvfrom結(jié)束時(shí)，計(jì)算時(shí)間之差，就可以得到相應(yīng)SQL的耗時(shí)了，如下：
- 先找到sendto與recvfrom系統(tǒng)調(diào)用在bpftrace中的追蹤點(diǎn)，如下：
- 編寫(xiě)追蹤腳本trace_slowsql_from_syscall.bt，腳本代碼如下：
其中，comm表示進(jìn)程名稱，tid表示線程號(hào)，@query[tid]與@start[tid]類似map，以tid為key的話，這個(gè)變量就像一個(gè)線程本地變量了。
3. 調(diào)用上面的腳本，可以看到各SQL執(zhí)行耗時(shí)，如下：
$ sudo BPFTRACE_STRLEN=80 bpftrace trace_slowsql_from_syscall.bt Attaching 3 probes... Tracing jdbc SQL slower than 0 ms by sendto/recvfrom syscall TIME(ms) PID MS QUERY 6398 3368243 125 select sleep(0.1) 16427 3368243 22 select id from app_log al order by id desc limit 1 16431 3368243 20 select id,log_info,create_time,update_time,add_time from app_log where id=11692 17492 3368243 21 select id,log_info,create_time,update_time,add_time from app_log where id=29214實(shí)例：在服務(wù)端追蹤慢SQL
從調(diào)用端來(lái)追蹤SQL耗時(shí)，會(huì)包含網(wǎng)絡(luò)往返時(shí)間，為了得到更精確的SQL耗時(shí)，我們可以寫(xiě)一個(gè)追蹤服務(wù)端mysql的腳本，來(lái)觀測(cè)SQL耗時(shí)，如下：
- 確定mysqld服務(wù)進(jìn)程的可執(zhí)行文件與入口函數(shù)
- 使用uprobe追蹤dispatch_command的調(diào)用，如下：
追蹤腳本整體上與之前系統(tǒng)調(diào)用版本的類似，不過(guò)追蹤點(diǎn)不一樣而已。
實(shí)例：找出掃描大量行的SQL
眾所周知，SQL執(zhí)行時(shí)需要掃描數(shù)據(jù)，并且掃描的數(shù)據(jù)越多，SQL性能就會(huì)越差。
但對(duì)于一些中間情況，SQL掃描行數(shù)不多也不少，如2w條。且這2w條數(shù)據(jù)都在緩存中的話，SQL執(zhí)行時(shí)間不會(huì)很長(zhǎng)，導(dǎo)致沒(méi)有記錄在慢查詢?nèi)罩局?#xff0c;但如果這樣的SQL并發(fā)量大起來(lái)的話，會(huì)非常耗費(fèi)CPU。
對(duì)于mysql的話，掃描行的函數(shù)是row_search_mvcc，如果你經(jīng)常抓取mysql棧的話，很容易發(fā)現(xiàn)這個(gè)函數(shù)，如下：
mysql每掃一行調(diào)用一次row_search_mvcc，如果在追蹤腳本中追蹤此函數(shù)，記錄下調(diào)用次數(shù)，就可以觀測(cè)SQL的掃描行數(shù)了，如下：
#!/usr/bin/bpftrace BEGIN{printf("Tracing mysqld SQL scan row than %d. Ctrl-C to end.\n", $1);printf("%-10s %-6s %6s %10s %s\n", "TIME(ms)", "PID", "MS", "SCAN_NUM", "QUERY"); } uprobe:/usr/local/mysql/bin/mysqld:*dispatch_command*{$COM_QUERY = (uint8)3;if (arg2 == $COM_QUERY) {@query[tid] = str(*arg1);@start[tid] = nsecs;} } uprobe:/usr/local/mysql/bin/mysqld:*row_search_mvcc*{@scan_num[tid]++; } uretprobe:/usr/local/mysql/bin/mysqld:*dispatch_command* /@start[tid]/{$dur = (nsecs - @start[tid]) / 1000000;if (@scan_num[tid] > $1) {printf("%-10u %-6d %6d %10d %s\n", elapsed / 1000000, pid, $dur, @scan_num[tid], @query[tid]);}delete(@query[tid]);delete(@start[tid]);delete(@scan_num[tid]); }腳本運(yùn)行效果如下：
$ sudo BPFTRACE_STRLEN=80 bpftrace trace_mysql_scan.bt 200 Attaching 4 probes... Tracing mysqld SQL scan row than 200. Ctrl-C to end. TIME(ms) PID MS SCAN_NUM QUERY 150614 1892 4 300 select * from app_log limit 300# 全表掃描，慢！ 17489 1892 424 43717 select count(*) from app_log # 大范圍索引掃描，慢！ 193013 1892 253 20000 select count(*) from app_log where id < 20000 # 深分頁(yè)，會(huì)查詢前20300條，取最后300條，慢！ 213395 1892 209 20300 select * from app_log limit 20000,300 # 索引效果不佳，雖然只會(huì)查到一條數(shù)據(jù)，但掃描數(shù)據(jù)量不會(huì)少，慢！ 430374 1892 186 15000 select * from app_log where id < 20000 and seq = 15000 limit 1如上所示，app_log是我建的一張測(cè)試表，共43716條數(shù)據(jù)，其中id字段是自增主鍵，seq值與id值一樣，但沒(méi)有索引。
可以看到上面的幾個(gè)場(chǎng)景，不管什么場(chǎng)景，只要掃描行數(shù)變大，耗時(shí)就會(huì)變長(zhǎng)，但也都沒(méi)有超過(guò)500毫秒的，原因是這個(gè)表很小，數(shù)據(jù)可以全部緩存在內(nèi)存中。
可見(jiàn)，像bpftrace這樣的動(dòng)態(tài)追蹤工具是非常強(qiáng)大的，而且比arthas更加靈活，arthas只能追蹤單個(gè)函數(shù)，而bpftrace可以跨函數(shù)追蹤。
bpftrace使用手冊(cè)：https://github.com/iovisor/bpftrace/blob/master/docs/reference_guide.md
抓包工具
ngrep
ngrep也是一款抓包工具，它將包數(shù)據(jù)以文本形式直接顯示出來(lái)，對(duì)于簡(jiǎn)單場(chǎng)景的抓包，不需要wireshark配合，如下：
抓HTTP請(qǐng)求
ngrep -W byline port 8080抓取查詢SQL
ngrep -W byline 'select' port 4578tcpdump
tcpdump是一個(gè)通用抓包工具，一般用它來(lái)抓網(wǎng)絡(luò)包數(shù)據(jù)，然后再使用wireshark分析，如下：
抓取3961端口網(wǎng)絡(luò)包
tcpdump tcp -i eth0 -s 0 -c 10000 and port 3764 -w ./target.capwireshark分析
將target.cap導(dǎo)入到wireshark分析。
查看某一具體sql的網(wǎng)絡(luò)包交互情況，如下：
a. 先Decode相應(yīng)端口使用MySQL協(xié)議解析：
b. 如下，輸入mysql.query contains "5211117719406053"，查看SQL中包含單號(hào)5211117719406053的數(shù)據(jù)包：
抓包如何判斷是網(wǎng)絡(luò)慢還是后端處理慢？
為方便分析耗時(shí)，一般建議在wireshark上再添加如下兩列：
- tcpDelta = tcp.time_delta，表示在當(dāng)前tcp連接中，當(dāng)前包相對(duì)上一個(gè)包的時(shí)間差。
- ack_rtt = tcp.analysis.ack_rtt，表示tcp中的ack包，相對(duì)其數(shù)據(jù)包的時(shí)間差。
如下，找耗時(shí)最大的包：發(fā)現(xiàn)對(duì)于select t2.data as sapCustomerCode,t1.uniquecode as uniquecode from ...這條SQL，服務(wù)端回復(fù)ack很快，而在回復(fù)數(shù)據(jù)包時(shí)變慢，說(shuō)明是慢在MySQL處理上，而非網(wǎng)絡(luò)里，因?yàn)槿绻W(wǎng)絡(luò)慢的話，ack應(yīng)該也會(huì)變慢。
觀測(cè)工具總結(jié)
命令可用情況
由于應(yīng)用系統(tǒng)一般部署在Neo容器環(huán)境中，權(quán)限這一塊是受限的，在Neo環(huán)境中上述各工具命令的可用情況如下：
| 命令 | 是否可用 | 描述 |
| vmstat、mpstat、free | 可用 | |
| top、pidstat、iostat | 可用 | |
| iotop | 不可用 | 權(quán)限問(wèn)題，執(zhí)行會(huì)報(bào)錯(cuò) |
| nicstat、iftop、sar、dstat | 可用 | |
| jstack、jmap、arthas | 可用 | |
| strace | 可用 | |
| ngrep、tcpdump | 可用 | |
| perf、bcc、bpftrace | 不可用 | 需要CAP_SYS_ADMIN權(quán)限，Neo沒(méi)有授權(quán)此權(quán)限給業(yè)務(wù)容器 |
思考：問(wèn)題偶現(xiàn)或已經(jīng)發(fā)生過(guò)了，怎么辦？
上面使用各種工具排查問(wèn)題，都是建立在問(wèn)題正在發(fā)生的場(chǎng)景下，如果問(wèn)題偶然出現(xiàn)，或已經(jīng)發(fā)生完了，由于問(wèn)題現(xiàn)場(chǎng)已經(jīng)消失，使用命令工具就不太好使了。
這種情況的問(wèn)題排查，比較依賴于系統(tǒng)的建設(shè)，訂單組這邊為方便解決這種問(wèn)題，分別在如下幾個(gè)方面做了一些工作：
完善監(jiān)控系統(tǒng)
完善各維度的監(jiān)控系統(tǒng)，如：機(jī)器監(jiān)控、線程池、連接池、JVM監(jiān)控、數(shù)據(jù)庫(kù)監(jiān)控等。
機(jī)器監(jiān)控
主要監(jiān)控硬件資源，如CPU、內(nèi)存等，監(jiān)控?cái)?shù)據(jù)由Neo提供，可以理解為top命令數(shù)據(jù)被采集下來(lái)了。
線程池監(jiān)控
對(duì)于服務(wù)端程序來(lái)說(shuō)，線程是最重要的軟件資源之一，線程不夠了，程序啥事都沒(méi)法干了，這也是導(dǎo)致接口偶爾慢的主要原因之一。
連接池監(jiān)控
對(duì)于服務(wù)端程序來(lái)說(shuō)，數(shù)據(jù)庫(kù)連接也是最重要的軟件資源之一，連接不夠了，會(huì)導(dǎo)致線程阻塞，這也是導(dǎo)致接口偶爾慢的主要原因之一。
JVM監(jiān)控
jvm監(jiān)控，主要監(jiān)控堆內(nèi)存使用情況，以及gc情況，由于gc的不確定性，gc也是導(dǎo)致接口偶爾慢的主要原因之一，而如果是oom這種問(wèn)題，則會(huì)導(dǎo)致整個(gè)系統(tǒng)停擺。
數(shù)據(jù)庫(kù)監(jiān)控
業(yè)務(wù)監(jiān)控
根據(jù)系統(tǒng)所支撐的業(yè)務(wù)流程，建設(shè)一些業(yè)務(wù)維度的監(jiān)控面板。
短信預(yù)警
完善日志系統(tǒng)
日志有哪些？
nginx日志
如果你的服務(wù)前面有nginx，一定不要錯(cuò)過(guò)了nginx日志的檢查。
access日志
像tomcat、resin等web服務(wù)器，都提供有接口訪問(wèn)日志功能，記錄了請(qǐng)求時(shí)間、耗時(shí)等，強(qiáng)烈建議打開(kāi)。
springboot開(kāi)啟方法，application.yml文件中添加如下配置：
server:servlet:context-path: "/"tomcat:accesslog:enabled: truedirectory: /home/work/logs/applogs/oc-searchfile-date-format: .yyyy-MM-ddpattern: '%h %l %u %t "%r" %s %b %Dms "%{Referer}i" "%{User-Agent}i" "%{X-Request-ID}i" "%{X-Forwarded-For}i"'resin開(kāi)啟方法，resin.xml中添加如下配置：
gc日志
對(duì)于有g(shù)c的服務(wù)，gc日志一定要配置上，加入如下JVM參數(shù)即可開(kāi)啟：
-XX:-OmitStackTraceInFastThrow -Xloggc:/home/work/logs/applogs/gc-%t.log -XX:+PrintClassHistogram -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintAdaptiveSizePolicy -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/work/logs/applogs/dmesg
內(nèi)核日志，一般建議排查問(wèn)題沒(méi)有思路時(shí)，常規(guī)性的看一下這個(gè)日志。
# 像丟包、警告、錯(cuò)誤等情況，內(nèi)核會(huì)記錄下來(lái) dmesg | tail -n100 # 如果你的進(jìn)程莫名其妙掛掉了，很有可能是內(nèi)存不足，內(nèi)核殺死了你的服務(wù)進(jìn)程 dmesg | grep -i kill應(yīng)用日志
這個(gè)就是我們應(yīng)用里面的slf4j、log4j等輸出的日志了。
慢查詢?nèi)罩?/strong>
日志格式規(guī)范
時(shí)間、日志級(jí)別、機(jī)器、線程、日志記錄器名、trace_id、耗時(shí)、業(yè)務(wù)操作名、單號(hào)、異常堆棧等
注意以下場(chǎng)景：
1、打印異常時(shí)，將全部異常棧打印出來(lái)，而不要只打印message
// 不推薦，這樣打印異常，會(huì)導(dǎo)致異常棧丟失，難以定位問(wèn)題 log.error(e.getMessage); // 推薦寫(xiě)法 log.error(orderId + "xxx處理失敗", e);// 不推薦，原始異常丟失 try{... }catch(Exception e){throw new BizException("xxx處理失敗"); } // 推薦寫(xiě)法 try{... }catch(Exception e){throw new BizException("xxx處理失敗", e); }2、nginx傳遞的X-REQUEST-ID，直接記錄到日志中，便于追蹤
String logId = request.getHeader("X-REQUEST-ID"); log.info("logId:{}, {}訂單處理，耗時(shí){}ms", logId, orderId, cost);//最好通過(guò)日志的MDC機(jī)制，統(tǒng)一在日志框架中記錄 MDC.put("traceId", logId);?日志分析常見(jiàn)思路
查找異常值
查看日志是否有高耗時(shí)操作，或是否出現(xiàn)java異常。
關(guān)聯(lián)分析
時(shí)間關(guān)聯(lián)性：比如在某一時(shí)刻耗時(shí)請(qǐng)求增加，看看相同時(shí)間cpu、內(nèi)存、gc的情況。
線程關(guān)聯(lián)性：比如某一處理耗時(shí)增加，看看相同線程前后的日志是否有些不一樣的case。
調(diào)用關(guān)聯(lián)性：最常見(jiàn)的就是對(duì)比調(diào)用方與服務(wù)方相同trace_id的耗時(shí)情況，如果沒(méi)有傳遞trace_id，也可思考數(shù)據(jù)本身的關(guān)聯(lián)性，比如單號(hào)+時(shí)間這種，很多時(shí)候也能唯一確定一次調(diào)用。
分布情況
分析日志在時(shí)間、位置(機(jī)器,線程,接口,方法,錯(cuò)誤碼)、耗時(shí)上的分布。
掛腳本
arthas后臺(tái)任務(wù)
arthas可以通過(guò)添加&符號(hào)，使命令運(yùn)行在后臺(tái)模式，因此只需要添加條件，一段時(shí)間檢查結(jié)果即可。
# 添加后臺(tái)任務(wù)，監(jiān)測(cè)慢查詢SQL [arthas@3368243]$ watch com.mysql.jdbc.PreparedStatement execute '{target.toString()}' 'target.originalSql.contains("select") && #cost > 2000' -x 2 > slow_sql.log &# 與shell類似，可以通過(guò)jobs查看后臺(tái)任務(wù) [arthas@3368243]$ jobs定時(shí)檢測(cè)腳本
通過(guò)在機(jī)器上啟動(dòng)一些定時(shí)腳本，定時(shí)檢測(cè)問(wèn)題是否發(fā)生，如發(fā)生，則使用相關(guān)診斷命令并保存命令結(jié)果，如下：
# 當(dāng)系統(tǒng)健康檢查失敗2次時(shí)，自動(dòng)jstack while sleep 1;do res=$(curl 'http://localhost:8080/_health' --connect-timeout 2 --max-time 2 -sS 2>&1)[[ $res =~ "ok" ]] && ((fail_num=0)) || ((fail_num++))if [[ $fail_num -ge 2 ]];thenpid=$(pgrep -n java)jstack $pid >> jstack.log 2>&1fi done編碼規(guī)范
oom是魔鬼，系統(tǒng)一旦出現(xiàn)oom，會(huì)導(dǎo)致整個(gè)系統(tǒng)停擺，系統(tǒng)可用性迅速下降到接近0，為此，定下了2個(gè)專門(mén)的規(guī)范，盡量避免oom產(chǎn)生。
總結(jié)
如果一個(gè)偶現(xiàn)問(wèn)題，分析下來(lái)沒(méi)有思路了，考慮一下是否可以完善一下監(jiān)控系統(tǒng)或添加更詳細(xì)的日志，不要排查不出來(lái)，也不做進(jìn)一步的輔助排查問(wèn)題的嘗試。
其它命令
vmstat
vmstat全名是虛擬內(nèi)存統(tǒng)計(jì)信息命令，看起來(lái)好像是用來(lái)觀測(cè)內(nèi)存的，實(shí)際上cpu、內(nèi)存、io資源它都能觀測(cè)。
$ vmstat -w 1 procs -----------------------memory---------------------- ---swap-- -----io---- -system-- --------cpu--------r b swpd free buff cache si so bi bo in cs us sy id wa st4 0 0 12531512 102680 274940 0 0 0 3 0 3 0 0 100 0 02 0 0 12531512 102680 274940 0 0 0 0 106 55 25 0 75 0 02 0 0 12531512 102680 274940 0 0 0 0 105 58 25 0 75 0 02 0 0 12531512 102680 274940 0 0 0 0 105 56 25 0 75 0 01s顯示一次，第一行是系統(tǒng)啟動(dòng)以來(lái)的統(tǒng)計(jì)信息，一般可忽略不看，從第二行開(kāi)始看即可。
- r：cpu運(yùn)行隊(duì)列長(zhǎng)度，即有多少線程等待操作系統(tǒng)調(diào)度運(yùn)行，這可看做是cpu的飽和度指標(biāo)，長(zhǎng)時(shí)間處于高值一般都有問(wèn)題。
- b: 不可中斷阻塞的線程數(shù)量，一般就是阻塞于io訪問(wèn)的線程數(shù)量。
- swpd: 內(nèi)存交換到磁盤(pán)的內(nèi)存大小，單位kB
- free：剩余內(nèi)存大小，單位kB
- buff: 用于buff的內(nèi)存大小，單位kB
- cache：用于文件頁(yè)面緩存的內(nèi)存大小，單位kB
- si：磁盤(pán)換入到內(nèi)存的當(dāng)前速度，單位kB/s
- so：內(nèi)存換出到磁盤(pán)的當(dāng)前速度，單位kB/s
- bi：每秒讀取的磁盤(pán)塊數(shù)量，單位blocks/s
- bo：每秒寫(xiě)入的磁盤(pán)塊數(shù)量，單位blocks/s
- in：每秒中斷數(shù)量
- cs：每秒線程上下文切換次數(shù)
- us：cpu用戶態(tài)使用率
- sy：cpu內(nèi)核態(tài)使用率
- id：cpu空閑率
- wa：等待I/O，線程被阻塞等待磁盤(pán)I/O時(shí)的CPU空閑時(shí)間占總時(shí)間的比例
- st：steal偷取，CPU在虛擬化環(huán)境下在其他租戶上的開(kāi)銷
mpstat
mpstat是用來(lái)查看cpu上各個(gè)核的cpu使用率的，如下：
$ mpstat -P ALL 1 Linux 4.19.128-microsoft-standard (DESKTOP-GC9LLHC) 10/24/21 _x86_64_ (8 CPU)12:39:37 CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle 12:39:38 all 24.57 0.00 0.00 0.00 0.00 1.72 0.00 0.00 0.00 73.71 12:39:38 0 0.00 0.00 0.00 0.00 0.00 12.28 0.00 0.00 0.00 87.72 12:39:38 1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00 12:39:38 2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00 12:39:38 3 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 12:39:38 4 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00 12:39:38 5 100.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 12:39:38 6 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00 12:39:38 7 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00如上，可見(jiàn)3、5號(hào)核的cpu使用率基本滿載，而其它核非常空閑，這一般是由于程序多線程設(shè)計(jì)上有問(wèn)題，導(dǎo)致某部分線程非常忙，另一部分線程沒(méi)事干，而mpstat就是用來(lái)觀測(cè)是否有這種cpu核負(fù)載不均的問(wèn)題的。
pidstat
pidstat基本和top功能是類似的，不過(guò)它是非交互式的命令，一般作為top的補(bǔ)充使用，如下：
# 默認(rèn)查看活動(dòng)進(jìn)程的cpu使用情況，加-t可以查看線程的 $ pidstat 1 13:32:45 UID PID %usr %system %guest %wait %CPU CPU Command 13:32:46 1000 3051 0.00 1.00 0.00 0.00 1.00 1 java 13:32:46 1000 3241 100.00 0.00 0.00 0.00 100.00 7 stress 13:32:46 1000 3242 100.00 0.00 0.00 0.00 100.00 5 stressAverage: UID PID %usr %system %guest %wait %CPU CPU Command Average: 1000 3051 0.00 0.33 0.00 0.00 0.33 - java Average: 1000 3241 100.00 0.00 0.00 0.00 100.00 - stress Average: 1000 3242 100.00 0.00 0.00 0.00 100.00 - stress# -w可以看線程上下文切換情況 # cswch/s：自愿上下文切換，比如等待io或鎖 # nvcswch/s：非自愿上下文切換，比如分給自己時(shí)間片用完了，一般需要關(guān)注這個(gè)，因?yàn)楝F(xiàn)在的程序大多是io密集型的，用完時(shí)間片的機(jī)會(huì)很少 $ pidstat -w 1 13:37:57 UID PID cswch/s nvcswch/s Command 13:37:58 1000 3299 1.00 0.00 pidstat13:37:58 UID PID cswch/s nvcswch/s Command 13:37:59 0 8 1.00 0.00 init 13:37:59 1000 9 1.00 0.00 wsltermd 13:37:59 1000 3299 1.00 0.00 pidstat# -v可以看運(yùn)行進(jìn)程的線程數(shù)與文件描述符數(shù)量 $ pidstat -v 1 01:41:34 PM UID PID threads fd-nr Command 01:41:35 PM 1000 876 95 177 java# -r可以看運(yùn)行進(jìn)程的內(nèi)存使用情況以及缺頁(yè)情況 # minflt/s：輕微缺頁(yè)，一般不用太關(guān)注 # majflt/s：嚴(yán)重缺頁(yè)，一般意味著發(fā)生了swrap，量較大時(shí)需要關(guān)注 $ pidstat -r 1 02:07:24 PM UID PID minflt/s majflt/s VSZ RSS %MEM Command 02:07:25 PM 999 2786 2.00 0.00 52792 3140 0.08 redis-server 02:07:25 PM 1000 601098 1.00 0.00 13976 6296 0.16 sshd# -d可以看某個(gè)進(jìn)程的io使用情況 $ pidstat -d 1 14:12:06 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 14:12:07 1000 3051 0.00 80.00 0.00 0 java 14:12:07 1000 3404 0.00 0.00 0.00 79 stressfree
其實(shí)上面的vmstat、top已經(jīng)可以看到內(nèi)存使用情況了，free命令更純粹一點(diǎn)，如下：
# 查看內(nèi)存使用情況，-m以MB為單位，-g可以使其以GB為單位 $ free -mtotal used free shared buff/cache available Mem: 3907 1117 778 3 2012 2503 Swap: 1897 708 1189要特別注意里面的free、buff/cache以及available，如下：
- free：系統(tǒng)空閑內(nèi)存，一般來(lái)說(shuō)，隨著使用時(shí)間越來(lái)越長(zhǎng)，Linux中free會(huì)越來(lái)越小，原因是Linux會(huì)把訪問(wèn)的文件數(shù)據(jù)盡可能地緩存在內(nèi)存中，以便下次讀取時(shí)能快速返回
- buff/cache：就是文件緩存到內(nèi)存中所占內(nèi)存的大小
- available：系統(tǒng)真正的可用內(nèi)存，約等于free+buff/cache，所以系統(tǒng)內(nèi)存是否足夠，你應(yīng)該看available的值。
df
df命令可以很容易的看到文件系統(tǒng)的空間使用情況，如下：
$ df -h Filesystem Size Used Avail Use% Mounted on udev 1.9G 0 1.9G 0% /dev tmpfs 391M 2.7M 389M 1% /run /dev/sda1 276G 150G 115G 57% / tmpfs 2.0G 0 2.0G 0% /dev/shm tmpfs 5.0M 4.0K 5.0M 1% /run/lock/dev/sda1的Use%這一列可以看到磁盤(pán)使用了57%了。
nicstat
nicstat可以查看整個(gè)網(wǎng)卡的使用情況，如下：
$ nicstat -z 1Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:22 ens33 38.09 7.13 32.03 6.77 1217.8 1078.4 0.03 0.00 22:35:22 lo 0.07 0.07 0.36 0.36 207.6 207.6 0.00 0.00Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:23 ens33 0.27 0.56 3.99 4.99 69.50 114.0 0.00 0.00Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:24 ens33 0.21 0.34 3.00 3.00 72.67 116.7 0.00 0.00Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:25 ens33 0.28 0.33 4.00 3.00 70.50 111.3 0.00 0.00Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:26 ens33 0.34 0.34 5.00 3.00 69.20 116.7 0.00 0.00Time Int rKB/s wKB/s rPk/s wPk/s rAvs wAvs %Util Sat 22:35:27 ens33 0.28 0.33 4.00 3.00 70.50 111.3 0.00 0.00其中%Util就是網(wǎng)卡帶寬的使用率了。
分享一個(gè)快速查找「占用CPU較高問(wèn)題代碼」的shell腳本：https://raw.githubusercontent.com/xiaoxi666/scripts/main/show-busy-java-threads。線上機(jī)器直接wget下載執(zhí)行（sh show-busy-java-threads）即可。默認(rèn)會(huì)輸出占用CPU最高的5個(gè)線程，也可自行設(shè)置參數(shù)。思路也是讓機(jī)器快速執(zhí)行多條命令，代替人工操作。
?
PS：腳本源于開(kāi)源項(xiàng)目GitHub - Wekoi/awesome-scripts: useful scripts for Linux op，里面還有不少其他好用的腳本，有需要的同學(xué)可參考使用。
總結(jié)
- 上一篇： 联想主板9针开关接线图_针式打印机不开机
- 下一篇： 常微分方程的解法 (二): 欧拉（Eul