jvm調(diào)優(yōu)的幾種場(chǎng)景(小結(jié))

更新時(shí)間：2022年01月20日 10:48:54 作者：我是滿(mǎn)意吖

本文主要介紹了jvm調(diào)優(yōu)的幾種場(chǎng)景，文中通過(guò)示例代碼介紹的非常詳細(xì)，具有一定的參考價(jià)值，感興趣的小伙伴們可以參考一下

一、cpu占用過(guò)高

cpu占用過(guò)高要分情況討論，是不是業(yè)務(wù)上在搞活動(dòng)，突然有大批的流量進(jìn)來(lái)，而且活動(dòng)結(jié)束后cpu占用率就下降了，如果是這種情況其實(shí)可以不用太關(guān)心，因?yàn)檎?qǐng)求越多，需要處理的線程數(shù)越多，這是正常的現(xiàn)象。話說(shuō)回來(lái)，如果你的服務(wù)器配置本身就差，cpu也只有一個(gè)核心，這種情況，稍微多一點(diǎn)流量就真的能夠把你的cpu資源耗盡，這時(shí)應(yīng)該考慮先把配置提升吧。

第二種情況，cpu占用率長(zhǎng)期過(guò)高，這種情況下可能是你的程序有那種循環(huán)次數(shù)超級(jí)多的代碼，甚至是出現(xiàn)死循環(huán)了。排查步驟如下：

（1）用top命令查看cpu占用情況

這樣就可以定位出cpu過(guò)高的進(jìn)程。在linux下，top命令獲得的進(jìn)程號(hào)和jps工具獲得的vmid是相同的：

（2）用top -Hp命令查看線程的情況

可以看到是線程id為7287這個(gè)線程一直在占用cpu

（3）把線程號(hào)轉(zhuǎn)換為16進(jìn)制

[root@localhost ~]# printf "%x" 7287
1c77

記下這個(gè)16進(jìn)制的數(shù)字，下面我們要用

（4）用jstack工具查看線程棧情況

[root@localhost ~]# jstack 7268 | grep 1c77 -A 10
"http-nio-8080-exec-2" #16 daemon prio=5 os_prio=0 tid=0x00007fb66ce81000 nid=0x1c77 runnable [0x00007fb639ab9000]
   java.lang.Thread.State: RUNNABLE
	at com.spareyaya.jvm.service.EndlessLoopService.service(EndlessLoopService.java:19)
	at com.spareyaya.jvm.controller.JVMController.endlessLoop(JVMController.java:30)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)

通過(guò)jstack工具輸出現(xiàn)在的線程棧，再通過(guò)grep命令結(jié)合上一步拿到的線程16進(jìn)制的id定位到這個(gè)線程的運(yùn)行情況，其中jstack后面的7268是第（1）步定位到的進(jìn)程號(hào)，grep后面的是（2）、（3）步定位到的線程號(hào)。

從輸出結(jié)果可以看到這個(gè)線程處于運(yùn)行狀態(tài)，在執(zhí)行com.spareyaya.jvm.service.EndlessLoopService.service這個(gè)方法，代碼行號(hào)是19行，這樣就可以去到代碼的19行，找到其所在的代碼塊，看看是不是處于循環(huán)中，這樣就定位到了問(wèn)題。

二、死鎖

死鎖并沒(méi)有第一種場(chǎng)景那么明顯，web應(yīng)用肯定是多線程的程序，它服務(wù)于多個(gè)請(qǐng)求，程序發(fā)生死鎖后，死鎖的線程處于等待狀態(tài)（WAITING或TIMED_WAITING），等待狀態(tài)的線程不占用cpu，消耗的內(nèi)存也很有限，而表現(xiàn)上可能是請(qǐng)求沒(méi)法進(jìn)行，最后超時(shí)了。在死鎖情況不多的時(shí)候，這種情況不容易被發(fā)現(xiàn)。

可以使用jstack工具來(lái)查看

（1）jps查看java進(jìn)程

[root@localhost ~]# jps -l
8737 sun.tools.jps.Jps
8682 jvm-0.0.1-SNAPSHOT.jar

（2）jstack查看死鎖問(wèn)題

由于web應(yīng)用往往會(huì)有很多工作線程，特別是在高并發(fā)的情況下線程數(shù)更多，于是這個(gè)命令的輸出內(nèi)容會(huì)十分多。jstack最大的好處就是會(huì)把產(chǎn)生死鎖的信息（包含是什么線程產(chǎn)生的）輸出到最后，所以我們只需要看最后的內(nèi)容就行了

Java stack information for the threads listed above:
===================================================
"Thread-4":
	at com.spareyaya.jvm.service.DeadLockService.service2(DeadLockService.java:35)
	- waiting to lock <0x00000000f5035ae0> (a java.lang.Object)
	- locked <0x00000000f5035af0> (a java.lang.Object)
	at com.spareyaya.jvm.controller.JVMController.lambda$deadLock$1(JVMController.java:41)
	at com.spareyaya.jvm.controller.JVMController$$Lambda$457/1776922136.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
"Thread-3":
	at com.spareyaya.jvm.service.DeadLockService.service1(DeadLockService.java:27)
	- waiting to lock <0x00000000f5035af0> (a java.lang.Object)
	- locked <0x00000000f5035ae0> (a java.lang.Object)
	at com.spareyaya.jvm.controller.JVMController.lambda$deadLock$0(JVMController.java:37)
	at com.spareyaya.jvm.controller.JVMController$$Lambda$456/474286897.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

Found 1 deadlock.

發(fā)現(xiàn)了一個(gè)死鎖，原因也一目了然。

三、內(nèi)存泄漏

我們都知道，java和c++的最大區(qū)別是前者會(huì)自動(dòng)收回不再使用的內(nèi)存，后者需要程序員手動(dòng)釋放。在c++中，如果我們忘記釋放內(nèi)存就會(huì)發(fā)生內(nèi)存泄漏。但是，不要以為jvm幫我們回收了內(nèi)存就不會(huì)出現(xiàn)內(nèi)存泄漏。

程序發(fā)生內(nèi)存泄漏后，進(jìn)程的可用內(nèi)存會(huì)慢慢變少，最后的結(jié)果就是拋出OOM錯(cuò)誤。發(fā)生OOM錯(cuò)誤后可能會(huì)想到是內(nèi)存不夠大，于是把-Xmx參數(shù)調(diào)大，然后重啟應(yīng)用。這么做的結(jié)果就是，過(guò)了一段時(shí)間后，OOM依然會(huì)出現(xiàn)。最后無(wú)法再調(diào)大最大堆內(nèi)存了，結(jié)果就是只能每隔一段時(shí)間重啟一下應(yīng)用。

內(nèi)存泄漏的另一個(gè)可能的表現(xiàn)是請(qǐng)求的響應(yīng)時(shí)間變長(zhǎng)了。這是因?yàn)轭l繁發(fā)生的GC會(huì)暫停其它所有線程（Stop The World）造成的。

為了模擬這個(gè)場(chǎng)景，使用了以下的程序

import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class Main {

    public static void main(String[] args) {
        Main main = new Main();
        while (true) {
            try {
                Thread.sleep(1);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            main.run();
        }
    }

    private void run() {
        ExecutorService executorService = Executors.newCachedThreadPool();
        for (int i = 0; i < 10; i++) {
            executorService.execute(() -> {
                // do something...
            });
        }
    }
}

運(yùn)行參數(shù)是-Xms20m -Xmx20m -XX:+PrintGC，把可用內(nèi)存調(diào)小一點(diǎn)，并且在發(fā)生gc時(shí)輸出信息，運(yùn)行結(jié)果如下

...
[GC (Allocation Failure)  12776K->10840K(18432K), 0.0309510 secs]
[GC (Allocation Failure)  13400K->11520K(18432K), 0.0333385 secs]
[GC (Allocation Failure)  14080K->12168K(18432K), 0.0332409 secs]
[GC (Allocation Failure)  14728K->12832K(18432K), 0.0370435 secs]
[Full GC (Ergonomics)  12832K->12363K(18432K), 0.1942141 secs]
[Full GC (Ergonomics)  14923K->12951K(18432K), 0.1607221 secs]
[Full GC (Ergonomics)  15511K->13542K(18432K), 0.1956311 secs]
...
[Full GC (Ergonomics)  16382K->16381K(18432K), 0.1734902 secs]
[Full GC (Ergonomics)  16383K->16383K(18432K), 0.1922607 secs]
[Full GC (Ergonomics)  16383K->16383K(18432K), 0.1824278 secs]
[Full GC (Allocation Failure)  16383K->16383K(18432K), 0.1710382 secs]
[Full GC (Ergonomics)  16383K->16382K(18432K), 0.1829138 secs]
[Full GC (Ergonomics) Exception in thread "main"  16383K->16382K(18432K), 0.1406222 secs]
[Full GC (Allocation Failure)  16382K->16382K(18432K), 0.1392928 secs]
[Full GC (Ergonomics)  16383K->16382K(18432K), 0.1546243 secs]
[Full GC (Ergonomics)  16383K->16382K(18432K), 0.1755271 secs]
[Full GC (Ergonomics)  16383K->16382K(18432K), 0.1699080 secs]
[Full GC (Allocation Failure)  16382K->16382K(18432K), 0.1697982 secs]
[Full GC (Ergonomics)  16383K->16382K(18432K), 0.1851136 secs]
[Full GC (Allocation Failure)  16382K->16382K(18432K), 0.1655088 secs]
java.lang.OutOfMemoryError: Java heap space

可以看到雖然一直在gc，占用的內(nèi)存卻越來(lái)越多，說(shuō)明程序有的對(duì)象無(wú)法被回收。但是上面的程序?qū)ο蠖际嵌x在方法內(nèi)的，屬于局部變量，局部變量在方法運(yùn)行結(jié)果后，所引用的對(duì)象在gc時(shí)應(yīng)該被回收啊，但是這里明顯沒(méi)有。

為了找出到底是哪些對(duì)象沒(méi)能被回收，我們加上運(yùn)行參數(shù)-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.bin，意思是發(fā)生OOM時(shí)把堆內(nèi)存信息dump出來(lái)。運(yùn)行程序直至異常，于是得到heap.dump文件，然后我們借助eclipse的MAT插件來(lái)分析，如果沒(méi)有安裝需要先安裝。

然后File->Open Heap Dump... ，然后選擇剛才dump出來(lái)的文件，選擇Leak Suspects

MAT會(huì)列出所有可能發(fā)生內(nèi)存泄漏的對(duì)象

可以看到居然有21260個(gè)Thread對(duì)象，3386個(gè)ThreadPoolExecutor對(duì)象，如果你去看一下java.util.concurrent.ThreadPoolExecutor的源碼，可以發(fā)現(xiàn)線程池為了復(fù)用線程，會(huì)不斷地等待新的任務(wù)，線程也不會(huì)回收，需要調(diào)用其shutdown方法才能讓線程池執(zhí)行完任務(wù)后停止。

其實(shí)線程池定義成局部變量，好的做法是設(shè)置成單例。

上面只是其中一種處理方法

在線上的應(yīng)用，內(nèi)存往往會(huì)設(shè)置得很大，這樣發(fā)生OOM再把內(nèi)存快照dump出來(lái)的文件就會(huì)很大，可能大到在本地的電腦中已經(jīng)無(wú)法分析了（因?yàn)閮?nèi)存不足夠打開(kāi)這個(gè)dump文件）。這里介紹另一種處理辦法：

（1）用jps定位到進(jìn)程號(hào)

C:\Users\spareyaya\IdeaProjects\maven-project\target\classes\org\example\net>jps -l
24836 org.example.net.Main
62520 org.jetbrains.jps.cmdline.Launcher
129980 sun.tools.jps.Jps
136028 org.jetbrains.jps.cmdline.Launcher

因?yàn)橐呀?jīng)知道了是哪個(gè)應(yīng)用發(fā)生了OOM，這樣可以直接用jps找到進(jìn)程號(hào)135988

（2）用jstat分析gc活動(dòng)情況

jstat是一個(gè)統(tǒng)計(jì)java進(jìn)程內(nèi)存使用情況和gc活動(dòng)的工具，參數(shù)可以有很多，可以通過(guò)jstat -help查看所有參數(shù)以及含義

C:\Users\spareyaya\IdeaProjects\maven-project\target\classes\org\example\net>jstat -gcutil -t -h8 24836 1000
Timestamp         S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
           29.1  32.81   0.00  23.48  85.92  92.84  84.13     14    0.339     0    0.000    0.339
           30.1  32.81   0.00  78.12  85.92  92.84  84.13     14    0.339     0    0.000    0.339
           31.1   0.00   0.00  22.70  91.74  92.72  83.71     15    0.389     1    0.233    0.622

上面是命令意思是輸出gc的情況，輸出時(shí)間，每8行輸出一個(gè)行頭信息，統(tǒng)計(jì)的進(jìn)程號(hào)是24836，每1000毫秒輸出一次信息。

輸出信息是Timestamp是距離jvm啟動(dòng)的時(shí)間，S0、S1、E是新生代的兩個(gè)Survivor和Eden，O是老年代區(qū)，M是Metaspace，CCS使用壓縮比例，YGC和YGCT分別是新生代gc的次數(shù)和時(shí)間，F(xiàn)GC和FGCT分別是老年代gc的次數(shù)和時(shí)間，GCT是gc的總時(shí)間。雖然發(fā)生了gc，但是老年代內(nèi)存占用率根本沒(méi)下降，說(shuō)明有的對(duì)象沒(méi)法被回收（當(dāng)然也不排除這些對(duì)象真的是有用）。

（3）用jmap工具dump出內(nèi)存快照

jmap可以把指定java進(jìn)程的內(nèi)存快照dump出來(lái)，效果和第一種處理辦法一樣，不同的是它不用等OOM就可以做到，而且dump出來(lái)的快照也會(huì)小很多。

jmap -dump:live,format=b,file=heap.bin 24836

這時(shí)會(huì)得到heap.bin的內(nèi)存快照文件，然后就可以用eclipse來(lái)分析了。

四、總結(jié)

以上三種嚴(yán)格地說(shuō)還算不上jvm的調(diào)優(yōu)，只是用了jvm工具把代碼中存在的問(wèn)題找了出來(lái)。我們進(jìn)行jvm的主要目的是盡量減少停頓時(shí)間，提高系統(tǒng)的吞吐量。但是如果我們沒(méi)有對(duì)系統(tǒng)進(jìn)行分析就盲目去設(shè)置其中的參數(shù)，可能會(huì)得到更壞的結(jié)果，jvm發(fā)展到今天，各種默認(rèn)的參數(shù)可能是實(shí)驗(yàn)室的人經(jīng)過(guò)多次的測(cè)試來(lái)做平衡的，適用大多數(shù)的應(yīng)用場(chǎng)景。如果你認(rèn)為你的jvm確實(shí)有調(diào)優(yōu)的必要，也務(wù)必要取樣分析，最后還得慢慢多次調(diào)節(jié)，才有可能得到更優(yōu)的效果。

到此這篇關(guān)于jvm調(diào)優(yōu)的幾種場(chǎng)景(小結(jié))的文章就介紹到這了,更多相關(guān)jvm調(diào)優(yōu) 內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！

您可能感興趣的文章: