前言

Github:https://github.com/HealerJean

博客:http://blog.healerjean.com

1、虚拟机参数怎么配置

1578294958942

1、Java整个堆大小设置,Xmx 和 Xms设置为老年代存活对象的3-4倍,即FullGC之后的老年代内存占用的3-4倍

2、年轻代Xmn的设置为老年代存活对象的1-1.5倍。

3、老年代的内存大小设置为老年代存活对象的2-3倍。

4、永久代 PermSize和MaxPermSize设置为老年代存活对象的1.2-1.5倍。

1.1、 确定老年代运行大小

注意:CMS GC是会造成2次的FullGC次数增加,因为它会两次STW,

1.1.1、GC日志 (稳妥方式 )

JVM参数中添加GC日志,GC日志中会记录每次FullGC之后各代的内存大小,观察老年代GC之后的空间大小。可观察一段时间内(比如2天)的FullGC之后的内存情况,根据多次的FullGC之后的老年代的空间大小数据来预估FullGC之后老年代的存活对象大小(可根据多次FullGC之后的内存大小取平均值)

1.1.2、强制触发FULL GC

运行一段时间后,考虑强制触发full gc ,这样就知道稳定运行中老年代的大小,这样获取的数据也必将准确(如果不使用用这个命令,直接用后面 jstat gc 查看到的老年代内存是不准的)

注意:强制触发FullGC,会造成线上服务停顿(STW),要谨慎,建议的操作方式为,在强制FullGC前先把服务节点摘除,FullGC之后再将服务挂回可用节点,对外提供服务 ,然后在不同时间段触发FullGC,根据多次FullGC之后的老年代内存情况来预估FullGC之后的老年代存活对象大小

触发Full GC 的方法

jmap -dump:live,format=b,file=heap.tdump <pid> 将当前的存活对象dump到文件,此时会触发FullGC

jmap -histo:live <pid> 打印每个class的实例数目,内存占用,类全名信息.live子参数加上后,只统计活的对象数量. 此时会触发FullGC

1.2、查看运行情况

1.2.1、jstat:看内存分配

刚上线的新服务,不知道该设置多大的内存的时候,可以先多设置一点内存,然后根据GC之后的情况来进行分析。

./jstat -gc 12566 1000 100
[work@vm10-123-3-2 bin]$ ./jstat -gc 12566 1000 100
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
26176.0 26176.0 296.0   0.0   209792.0 169909.3  786432.0   149381.5  116424.0 109474.4 13108.0 11988.5    340    8.121   6      0.570    8.691
26176.0 26176.0 296.0   0.0   209792.0 169909.3  786432.0   149381.5  116424.0 109474.4 13108.0 11988.5    340    8.121   6      0.570    8.691
26176.0 26176.0 296.0   0.0   209792.0 169909.3  786432.0   149381.5  116424.0 109474.4 13108.0 11988.5    340    8.121   6      0.570    8.691
26176.0 26176.0 296.0   0.0   209792.0 169909.3  786432.0   149381.5  116424.0 109474.4 13108.0 11988.5    340    8.121   6      0.570    8.691
26176.0 26176.0 296.0   0.0   209792.0 169922.4  786432.0   149381.5  116424.0 109474.4 13108.0 11988.5    340    8.121   6      0.570    8.691

1578463100026

年轻代GC平均耗时:8.121s/340 = 0.023秒 = 23毫秒

老年代GC平均耗时 0.57/6 =0.095秒 = 95毫秒

查看年轻代GC频率,可以再线上直接使用该命令进行推导 ,很简单。看看多长时间GC一次

1.2.2、jmap:查看堆内存情况

./jmap -heap 12566
[work@vm10-123-3-2 bin]$ ./jmap -heap 12566
Attaching to process ID 12566, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.202-b08

using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 1073741824 (1024.0MB)
   NewSize                  = 268435456 (256.0MB)
   MaxNewSize               = 268435456 (256.0MB)
   OldSize                  = 805306368 (768.0MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage: 
New Generation (Eden + 1 Survivor Space):  //新生代区域分配情况
   capacity = 241631232 (230.4375MB)
   used     = 26757744 (25.518173217773438MB)
   free     = 214873488 (204.91932678222656MB)
   11.073793639391782% used
Eden Space:
   capacity = 214827008 (204.875MB)
   used     = 26537600 (25.3082275390625MB)
   free     = 188289408 (179.5667724609375MB)
   12.353009170988408% used
From Space: //其中一个Survivor区域分配情况
   capacity = 26804224 (25.5625MB)
   used     = 220144 (0.2099456787109375MB)
   free     = 26584080 (25.352554321289062MB)
   0.8213033886002445% used
To Space:   //另一个Survivor区域分配情况
   capacity = 26804224 (25.5625MB)
   used     = 0 (0.0MB)
   free     = 26804224 (25.5625MB)
   0.0% used
concurrent mark-sweep generation: //老生代区域分配情况
   capacity = 805306368 (768.0MB)
   used     = 152967632 (145.8813018798828MB)
   free     = 652338736 (622.1186981201172MB)
   18.99496118227641% used

42801 interned Strings occupying 4704176 bytes.

老年代占用内存145M左右,按照整个堆大小是老年代的3-4倍计算的话, 设置各代内存的情况如下

-Xms=640m -Xmx=640m Xmn=256m  

老年代大小为 640 - 256 = 384  384/145 = 2.6倍 符号推荐情况 

测试成果 :运行7.1.1命令,查看gc频率是否正常,满足需要

结果分析 :整体的GC耗时减少。但GC频率比之前的2G时的要多了一些。

1.3、总结:

在内存比较小的机器上,可以按照上述的方式来进行内存的调优, 找到一个在GC频率和GC耗时上都可接受的一个内存设置,可以用较小的内存满足当前的服务需要。但内存比较大的机器上,可以相对给服务多增加一点内存,可以减少GC的频率,GC的耗时相应会增加一些。

2、分析虚拟机错误

2.1、系统线程状态

2.1.1、系统线程状态为 deadlock

线程处于死锁状态,将占用系统大量资源。

class TestTask implements Runnable {
    private Object obj1;
    private Object obj2;
    private int order;

    public TestTask(int order, Object obj1, Object obj2) {
        this.order = order;
        this.obj1 = obj1;
        this.obj2 = obj2;
    }

    public void test1() throws InterruptedException {
        synchronized (obj1) {
            //建议线程调取器切换到其它线程运行
            Thread.yield();
            synchronized (obj2) {
                System.out.println("test。。。");
            }

        }
    }
    public void test2() throws InterruptedException {
        synchronized (obj2) {
            Thread.yield();
            synchronized (obj1) {
                System.out.println("test。。。");
            }

        }
    }

    @Override
    public void run() {

        while (true) {
            try {
                if(this.order == 1){
                    this.test1();
                }else{
                    this.test2();
                }
                
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

    }
}

public class Test {

    public static void main(String[] args) throws InterruptedException {
        Object obj1 = new Object();
        Object obj2 = new Object();

        ExecutorService ex = Executors.newFixedThreadPool(10);
        // 起10个线程
        for (int i = 0; i < 10; i++) {
            int order = i%2==0 ? 1 : 0;
            ex.execute(new TestTask(order, obj1, obj2));
        }

    }
}

1578384692827

2.1.2、系统线程状态为 waiting for monitor entryin Object.wait()

系统线程处于这种状态说明它在等待进入一个临界区,此时JVM线程的状态通常都是 java.lang.Thread.State: BLOCKED

如果大量线程处于这种状态的话,可能是一个全局锁阻塞了大量线程。如果短期内多次打印Thread Dump信息,发现 waiting for monitor entry 状态的线程越来越多,没有减少的趋势,可能意味着某些线程在临界区里呆得时间太长了,以至于越来越多新线程迟迟无法进入。

2.1.3、系统线程状态为 waiting on condition

系统线程处于此种状态说明它在等待另一个条件的发生来唤醒自己,或者自己调用了sleep()方法。

此时JVM线程的状态通常是java.lang.Thread.State: WAITING (parking)(等待唤醒条件)或java.lang.Thread.State: TIMED_WAITING (parking或sleeping)(等待定时唤醒条件)。

如果大量线程处于此种状态,说明这些线程又去获取第三方资源了,比如第三方的网络资源或读取数据库的操作,长时间无法获得响应,导致大量线程进入等待状态。因此,这说明系统处于一个网络瓶颈或读取数据库操作时间太长。

class TestTask implements Runnable {
    @Override
    public void run() {

        synchronized (this) {
            try {
                //等待被唤醒
                wait();
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }

    }
}

public class Test {

    public static void main(String[] args) throws InterruptedException {

        ExecutorService ex = Executors.newFixedThreadPool(1);
        ex.execute(new TestTask());

    }
}

1578384656158

2.1.4、系统线程状态为 blocked

线程处于阻塞状态,需要根据实际情况进行判断。

2.2、CPU飙升打印线程转储文件

1、top命令查看耗时最大的进程

2、ps命令查看耗时最大的进程

3、线程id,转换成16进制数

4、jstack打印命令栈,查看对应的进场在做什么事情;

2.1.1、top:命令确定内存情况,找到CPU过高的Java程序

1、top :命令

top 

1579177076808

2、P:根据CPU使用百分比大小进行排序

1579177169946

3、命令top -p 30030 :只观察进程为30030,CPU百分比最大的那个Java程序

top -p 30030

观察几分钟,发现一只占用超高,那么基本上定位到它了

1579177266043

2.1.2、判断是哪个Java程序

1、ps -ef |grep PID或者ps aux | grep PID

ps -ef 30030 
ps -aux 30030

定位到应用 asset-service占用比较高

1579177452257

2.1.3、定位哪个线程CPU比较高

top -H -p pid 、打印该进程下线程占用cpu情况 ,定位到线程 TID 30332 占用较高,讲它转化成16进制 767c

top -H -p 30030 :查看线程占用比例 得到线程30332 比较高
[work@vm10-123-3-2 ~]$ ps -mp 30030 -o THREAD,tid,time 
USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
work     95.9   -    - -         -      -     - 23-10:29:53
work      0.0  19    - futex_    -      - 30030 00:00:00
work      0.0  19    - futex_    -      - 30045 00:00:47
work      0.0  19    - futex_    -      - 30046 00:00:20
work      0.0  19    - futex_    -      - 30047 00:00:20
work      0.0  19    - futex_    -      - 30048 00:00:20
work     95.6  19    - -         -      - 30332 23-08:37:00





  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND               30332 work      20   0 10.338g 1.034g   5228 R 99.9  3.3  34523:57 java                   30206 work      20   0 10.338g 1.034g   5228 S  0.3  3.3  54:22.94 java                   31131 work      20   0 10.338g 1.034g   5228 S  0.3  3.3  12:37.95 java                   30030 work      20   0 10.338g 1.034g   5228 S  0.0  3.3   0:00.00 java                   30045 work      20   0 10.338g 1.034g   5228 S  0.0  3.3   0:48.52 java                   30046 work      20   0 10.338g 1.034g   5228 S  0.0  3.3   0:20.82 java                   30047 work      20   0 10.338g 1.034g   5228 S  0.0  3.3   0:20.83 java  



2.1.4、转储线程信息

2.1.5、下载到本地慢慢看

建议使用命令 jstack 30030 > 30030cpu.log 下载到本地查看,

2.1.6、线程直接看

9.3.1、查看线程id为30332的16进制为 767c的线程日志

./jstack 30030 | grep   767c   -A 10
[work@vm10-123-3-2 bin]$ ./jstack 30030 | grep   767c   -A 10
"ObjectCleanerThread" #85 daemon prio=1 os_prio=0 tid=0x00007f20e290c800 nid=0x767c runnable [0x00007f20ec5a6000]
   java.lang.Thread.State: RUNNABLE
        at io.netty.util.Recycler$WeakOrderQueue$Head.run(Recycler.java:264)
        at io.netty.util.internal.ObjectCleaner$AutomaticCleanerReference.cleanup(ObjectCleaner.java:143)
        at io.netty.util.internal.ObjectCleaner$1.run(ObjectCleaner.java:62)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)

"Log4j2-TF-7-AsyncLoggerConfig--4" #81 daemon prio=5 os_prio=0 tid=0x00007f20e087e800 nid=0x75fe runnable [0x00007f20ec4a5000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
[work@vm10-123-3-2 bin]$ 

我们可以使用命令 cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c 来对 jstack 的状态有一个整体的把握,如果 WAITING 之类的特别多,那么多半是有问题啦。

9.4、堆的问题查看

堆的问题查看主要是查看服务器的日志或者是本地模拟调用情景再现。使用命令jstatjmap,看了上面的这两个命令就感觉应该比较简单了

ContactAuthor