Series columns: SERIES of JVM columns

JVM performance Tuning (1) — JVM memory model and class loading operation mechanism
JVM performance Tuning (2) — garbage collection algorithms and garbage collectors
JVM performance tuning (3) – Analyze garbage collection policies through GC logs
JVM performance tuning (4) – Memory allocation and garbage collection tuning
JVM Performance Tuning (5) – Performance tuning tools

Analyze JVM health with tools

In order to properly allocate memory and optimize GC, we found from the performance tuning process in the previous article that we need to know at least a few things: The growth rate of new generation objects, the trigger frequency of YoungGC, the duration of YoungGC, the size of surviving objects after each YoungGC, how many objects enter the old age after each YoungGC, the growth rate of old age objects, the trigger frequency of FullGC, the duration of FullGC, etc. We used the jstat tool to analyze GC logs or rough estimates for tuning.

Run the sample program

1. The following example code

This code simulates the creation of 20M objects per second in the new generation, which will become garbage after 1 second.

public class GCMain {
    static final int _1M = 1024 * 1024;

    public static void main(String[] args) {
        sleep(20);

        for (int i = 0; i < 100; i++) { loadData(i); }}// loadData Generates 20M objects each time. Each request takes 1 second
    public static void loadData(int index) {
        System.out.println("load data: " + index);
        byte[] data1 = new byte[_1M * 10];
        byte[] data2 = new byte[_1M * 10];

        sleep(1);
    }

    public static void sleep(long seconds) {
        try {
            Thread.sleep(seconds * 1000);
        } catch(InterruptedException e) { e.printStackTrace(); }}}Copy the code

2. Set JVM parameters

Before running the sample program, set the following JVM parameters: 100M for the new generation and 100M for the old generation, 80M for Eden, 10M for Survivor, and 20M for large objects.

-Xms200M
-Xmx200M
-Xmn100M
-XX:SurvivorRatio=8
-XX:MaxTenuringThreshold=5
-XX:PretenureSizeThreshold=20M
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=92
-XX:+UseCMSInitiatingOccupancyOnly
-XX:+UseCMSCompactAtFullCollection
-XX:CMSFullGCsBeforeCompaction=0
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-Xloggc:./gc.log
Copy the code

3. Estimate the memory operation model

Let’s start by estimating JVM performance based on this business code and JVM parameter configuration:

This code will generate 20M objects in Eden every second, which will fill Eden in 3-4 seconds. YoungGC will be triggered.
The number of live objects after YoungGC may exceed 10M, because data2 may be created when Eden space is insufficient and data1 is still alive. It may also be 0, and the Eden range will not be enough when data1 is created.
Since the Survivor zone is not enough to drop the YoungGC surviving objects, about 10M objects will enter the old age at a time; Considering the possibility that there will be no surviving objects after YoungGC, we estimate that 10M of YoungGC will enter the old age after 2 YoungGC.
YoungGC triggers once every 3 to 4 seconds, so after 18 times or so, YoungGC is about 60 seconds, the old age is almost full, and then the living object can not be put into the old age triggers FullGC.
Since CMS background reclaim threads trigger OldGC when the age exceeds 92%, it is also possible to trigger GC in about 60 seconds due to the age threshold exceeding 92%.

4, use JPS command to find the program PID

Run the program, first through the JPS -L command to find the PID of the program.

5. Run the jstat command to check GC status

Here’s what the jstat output looks like:

Mechrevo@hello-world MINGW64 ~/Desktop
$ jstat -gc 15488 1000 1000
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
10240.0 10240.0  0.0    0.0   81920.0   4984.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0   4984.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0   4984.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0   4984.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0   4984.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0  25464.1   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0  45944.2   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0    0.0   81920.0  66424.2   102400.0     0.0     4480.0 786.6  384.0   76.4       0    0.000   0      0.000    0.000
10240.0 10240.0  0.0   713.8  81920.0  11878.4   102400.0   10242.1   4864.0 3043.9 512.0  321.7       1    0.005   0      0.000    0.005
10240.0 10240.0  0.0   713.8  81920.0  33961.9   102400.0   10242.1   4864.0 3043.9 512.0  321.7       1    0.005   0      0.000    0.005
10240.0 10240.0  0.0   713.8  81920.0  54441.9   102400.0   10242.1   4864.0 3043.9 512.0  321.7       1    0.005   0      0.000    0.005
10240.0 10240.0  0.0   713.8  81920.0  74922.0   102400.0   10242.1   4864.0 3043.9 512.0  321.7       1    0.005   0      0.000    0.005
10240.0 10240.0 828.5   0.0   81920.0  22891.3   102400.0   10242.1   4864.0 3044.4 512.0  321.7       2    0.005   0      0.000    0.005
10240.0 10240.0 828.5   0.0   81920.0  43371.3   102400.0   10242.1   4864.0 3044.4 512.0  321.7       2    0.005   0      0.000    0.005
10240.0 10240.0 828.5   0.0   81920.0  63851.3   102400.0   10242.1   4864.0 3044.4 512.0  321.7       2    0.005   0      0.000    0.005
10240.0 10240.0  0.0   964.7  81920.0  10240.0   102400.0   20484.1   4864.0 3044.5 512.0  321.7       3    0.010   0      0.000    0.010
10240.0 10240.0  0.0   964.7  81920.0  32230.5   102400.0   20484.1   4864.0 3044.5 512.0  321.7       3    0.010   0      0.000    0.010
10240.0 10240.0  0.0   964.7  81920.0  52710.5   102400.0   20484.1   4864.0 3044.5 512.0  321.7       3    0.010   0      0.000    0.010
10240.0 10240.0  0.0   964.7  81920.0  73190.5   102400.0   20484.1   4864.0 3044.5 512.0  321.7       3    0.010   0      0.000    0.010
10240.0 10240.0 759.6   0.0   81920.0  22035.2   102400.0   20484.1   4864.0 3044.5 512.0  321.7       4    0.011   0      0.000    0.011
10240.0 10240.0 759.6   0.0   81920.0  42515.2   102400.0   20484.1   4864.0 3044.5 512.0  321.7       4    0.011   0      0.000    0.011
10240.0 10240.0 759.6   0.0   81920.0  62995.2   102400.0   20484.1   4864.0 3044.5 512.0  321.7       4    0.011   0      0.000    0.011
10240.0 10240.0  0.0   886.2  81920.0  10240.0   102400.0   30724.1   4864.0 3044.5 512.0  321.7       5    0.016   0      0.000    0.016
10240.0 10240.0  0.0   886.2  81920.0  32212.1   102400.0   30724.1   4864.0 3044.5 512.0  321.7       5    0.016   0      0.000    0.016
10240.0 10240.0  0.0   886.2  81920.0  52692.1   102400.0   30724.1   4864.0 3044.5 512.0  321.7       5    0.016   0      0.000    0.016
10240.0 10240.0  0.0   886.2  81920.0  73172.1   102400.0   30724.1   4864.0 3044.5 512.0  321.7       5    0.016   0      0.000    0.016
10240.0 10240.0  0.0    0.0   81920.0  22023.2   102400.0   31373.1   4864.0 3044.5 512.0  321.7       6    0.019   0      0.000    0.019
10240.0 10240.0  0.0    0.0   81920.0  42503.3   102400.0   31373.1   4864.0 3044.5 512.0  321.7       6    0.019   0      0.000    0.019
10240.0 10240.0  0.0    0.0   81920.0  62983.3   102400.0   31373.1   4864.0 3044.5 512.0  321.7       6    0.019   0      0.000    0.019
10240.0 10240.0  0.0    0.0   81920.0  10240.0   102400.0   41613.1   4864.0 3044.5 512.0  321.7       7    0.024   0      0.000    0.024
10240.0 10240.0  0.0    0.0   81920.0  32204.4   102400.0   41613.1   4864.0 3044.5 512.0  321.7       7    0.024   0      0.000    0.024
10240.0 10240.0  0.0    0.0   81920.0  52684.4   102400.0   41613.1   4864.0 3044.5 512.0  321.7       7    0.024   0      0.000    0.024
10240.0 10240.0  0.0    0.0   81920.0  73164.4   102400.0   41613.1   4864.0 3044.5 512.0  321.7       7    0.024   0      0.000    0.024
10240.0 10240.0  0.0    0.0   81920.0  22018.2   102400.0   41613.1   4864.0 3044.9 512.0  321.7       8    0.025   0      0.000    0.025
10240.0 10240.0  0.0    0.0   81920.0  42498.3   102400.0   41613.1   4864.0 3044.9 512.0  321.7       8    0.025   0      0.000    0.025
10240.0 10240.0  0.0    0.0   81920.0  62978.3   102400.0   41613.1   4864.0 3044.9 512.0  321.7       8    0.025   0      0.000    0.025
10240.0 10240.0  0.0    0.0   81920.0  10240.0   102400.0   51853.2   4864.0 3044.9 512.0  321.7       9    0.030   0      0.000    0.030
10240.0 10240.0  0.0    0.0   81920.0  32201.1   102400.0   51853.2   4864.0 3044.9 512.0  321.7       9    0.030   0      0.000    0.030
10240.0 10240.0  0.0    0.0   81920.0  52681.2   102400.0   51853.2   4864.0 3044.9 512.0  321.7       9    0.030   0      0.000    0.030
10240.0 10240.0  0.0    0.0   81920.0  73161.2   102400.0   51853.2   4864.0 3044.9 512.0  321.7       9    0.030   0      0.000    0.030
10240.0 10240.0  0.0    0.0   81920.0  22016.1   102400.0   51853.2   4864.0 3045.6 512.0  321.7      10    0.031   0      0.000    0.031
10240.0 10240.0  0.0    0.0   81920.0  42496.2   102400.0   51853.2   4864.0 3045.6 512.0  321.7      10    0.031   0      0.000    0.031
10240.0 10240.0  0.0    0.0   81920.0  62976.2   102400.0   51853.2   4864.0 3045.6 512.0  321.7      10    0.031   0      0.000    0.031
10240.0 10240.0  0.0    0.0   81920.0  10240.0   102400.0   62093.2   4864.0 3045.9 512.0  321.7      11    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  32199.8   102400.0   62093.2   4864.0 3045.9 512.0  321.7      11    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  52679.8   102400.0   62093.2   4864.0 3045.9 512.0  321.7      11    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  52679.8   102400.0   62093.2   4864.0 3045.9 512.0  321.7      11    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  22015.3   102400.0   62093.2   4864.0 3045.9 512.0  321.7      12    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  42495.3   102400.0   62093.2   4864.0 3045.9 512.0  321.7      12    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0  62975.3   102400.0   62093.2   4864.0 3045.9 512.0  321.7      12    0.036   0      0.000    0.036
10240.0 10240.0  0.0    0.0   81920.0    0.0     102400.0   72333.2   4864.0 3045.9 512.0  321.7      13    0.041   0      0.000    0.041
10240.0 10240.0  0.0    0.0   81920.0  32199.2   102400.0   72333.2   4864.0 3045.9 512.0  321.7      13    0.041   0      0.000    0.041
10240.0 10240.0  0.0    0.0   81920.0  52679.3   102400.0   72333.2   4864.0 3045.9 512.0  321.7      13    0.041   0      0.000    0.041
10240.0 10240.0  0.0    0.0   81920.0  74797.7   102400.0   72333.2   4864.0 3045.9 512.0  321.7      13    0.041   0      0.000    0.041
10240.0 10240.0  4.0    0.0   81920.0    0.0     102400.0   72333.2   4864.0 3048.0 512.0  321.7      14    0.042   0      0.000    0.042
10240.0 10240.0  4.0    0.0   81920.0  22014.9   102400.0   72333.2   4864.0 3048.0 512.0  321.7      14    0.042   0      0.000    0.042
10240.0 10240.0  4.0    0.0   81920.0  62975.0   102400.0   72333.2   4864.0 3048.0 512.0  321.7      14    0.042   0      0.000    0.042
10240.0 10240.0  0.0    2.0   81920.0  10240.0   102400.0   82573.2   4864.0 3048.0 512.0  321.7      15    0.047   0      0.000    0.047
10240.0 10240.0  0.0    2.0   81920.0  10240.0   102400.0   82573.2   4864.0 3048.0 512.0  321.7      15    0.047   0      0.000    0.047
10240.0 10240.0  0.0    2.0   81920.0  32199.0   102400.0   82573.2   4864.0 3048.0 512.0  321.7      15    0.047   0      0.000    0.047
10240.0 10240.0  0.0    2.0   81920.0  73159.1   102400.0   82573.2   4864.0 3048.0 512.0  321.7      15    0.047   0      0.000    0.047
10240.0 10240.0  4.0    0.0   81920.0    0.0     102400.0   82573.2   4864.0 3048.0 512.0  321.7      16    0.048   0      0.000    0.048
10240.0 10240.0  4.0    0.0   81920.0  22014.7   102400.0   82573.2   4864.0 3048.0 512.0  321.7      16    0.048   0      0.000    0.048
10240.0 10240.0  4.0    0.0   81920.0  62974.8   102400.0   82573.2   4864.0 3048.0 512.0  321.7      16    0.048   0      0.000    0.048
10240.0 10240.0  0.0    2.0   81920.0  10240.0   102400.0   10892.1   4864.0 3048.7 512.0  321.7      17    0.053   2      0.002    0.055
10240.0 10240.0  0.0    2.0   81920.0  10240.0   102400.0   10892.1   4864.0 3048.7 512.0  321.7      17    0.053   2      0.002    0.055
10240.0 10240.0  0.0    2.0   81920.0  32198.9   102400.0   10892.1   4864.0 3048.7 512.0  321.7      17    0.053   2      0.002    0.055
10240.0 10240.0  0.0    2.0   81920.0  73159.0   102400.0   10892.1   4864.0 3048.7 512.0  321.7      17    0.053   2      0.002    0.055
10240.0 10240.0  2.0    0.0   81920.0  22833.9   102400.0   10892.1   4864.0 3049.0 512.0  321.7      18    0.054   2      0.002    0.056
10240.0 10240.0  2.0    0.0   81920.0  22833.9   102400.0   10892.1   4864.0 3049.0 512.0  321.7      18    0.054   2      0.002    0.056
10240.0 10240.0  2.0    0.0   81920.0  43313.9   102400.0   10892.1   4864.0 3049.0 512.0  321.7      18    0.054   2      0.002    0.056
10240.0 10240.0  0.0    4.0   81920.0    0.0     102400.0   21132.1   4864.0 3049.0 512.0  321.7      19    0.056   2      0.002    0.058
10240.0 10240.0  0.0    4.0   81920.0  10240.0   102400.0   21132.1   4864.0 3049.0 512.0  321.7      19    0.056   2      0.002    0.058
10240.0 10240.0  0.0    4.0   81920.0  32193.5   102400.0   21132.1   4864.0 3049.0 512.0  321.7      19    0.056   2      0.002    0.058
10240.0 10240.0  0.0    4.0   81920.0  52673.6   102400.0   21132.1   4864.0 3049.0 512.0  321.7      19    0.056   2      0.002    0.058
10240.0 10240.0  2.0    0.0   81920.0  22011.2   102400.0   21132.1   4864.0 3049.0 512.0  321.7      20    0.057   2      0.002    0.058
10240.0 10240.0  2.0    0.0   81920.0  22011.2   102400.0   21132.1   4864.0 3049.0 512.0  321.7      20    0.057   2      0.002    0.058
10240.0 10240.0  2.0    0.0   81920.0  42491.2   102400.0   21132.1   4864.0 3049.0 512.0  321.7      20    0.057   2      0.002    0.058
10240.0 10240.0  0.0    4.0   81920.0    0.0     102400.0   31372.2   4864.0 3049.0 512.0  321.7      21    0.059   2      0.002    0.060
10240.0 10240.0  0.0    4.0   81920.0  10240.0   102400.0   31372.2   4864.0 3049.0 512.0  321.7      21    0.059   2      0.002    0.060
10240.0 10240.0  0.0    4.0   81920.0  32196.6   102400.0   31372.2   4864.0 3049.0 512.0  321.7      21    0.059   2      0.002    0.060
10240.0 10240.0  0.0    4.0   81920.0  52676.6   102400.0   31372.2   4864.0 3049.0 512.0  321.7      21    0.059   2      0.002    0.060
10240.0 10240.0  4.0    0.0   81920.0    0.0     102400.0   31372.2   4864.0 3049.0 512.0  321.7      22    0.059   2      0.002    0.061
10240.0 10240.0  4.0    0.0   81920.0  22013.2   102400.0   31372.2   4864.0 3049.0 512.0  321.7      22    0.059   2      0.002    0.061
10240.0 10240.0  4.0    0.0   81920.0  42493.2   102400.0   31372.2   4864.0 3049.0 512.0  321.7      22    0.059   2      0.002    0.061
10240.0 10240.0  0.0    4.0   81920.0    0.0     102400.0   41612.2   4864.0 3049.0 512.0  321.7      23    0.061   2      0.002    0.062
10240.0 10240.0  0.0    4.0   81920.0  10240.0   102400.0   41612.2   4864.0 3049.0 512.0  321.7      23    0.061   2      0.002    0.062
10240.0 10240.0  0.0    4.0   81920.0  32197.9   102400.0   41612.2   4864.0 3049.0 512.0  321.7      23    0.061   2      0.002    0.062
10240.0 10240.0  0.0    4.0   81920.0  52677.9   102400.0   41612.2   4864.0 3049.0 512.0  321.7      23    0.061   2      0.002    0.062
10240.0 10240.0  0.0    0.0   81920.0    0.0     102400.0   41612.2   4864.0 3049.0 512.0  321.7      24    0.061   2      0.002    0.063
10240.0 10240.0  0.0    0.0   81920.0  42494.1   102400.0   41612.2   4864.0 3049.0 512.0  321.7      24    0.061   2      0.002    0.063
10240.0 10240.0  0.0    0.0   81920.0  42494.1   102400.0   41612.2   4864.0 3049.0 512.0  321.7      24    0.061   2      0.002    0.063
10240.0 10240.0  0.0    0.0   81920.0    0.0     102400.0   51852.3   4864.0 3049.8 512.0  321.7      25    0.063   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  10240.0   102400.0   51852.3   4864.0 3049.8 512.0  321.7      25    0.063   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  32198.4   102400.0   51852.3   4864.0 3049.8 512.0  321.7      25    0.063   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  52678.5   102400.0   51852.3   4864.0 3049.8 512.0  321.7      25    0.063   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0    0.0     102400.0   51852.3   4864.0 3049.8 512.0  321.7      26    0.064   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  22014.4   102400.0   51852.3   4864.0 3049.8 512.0  321.7      26    0.064   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  42494.4   102400.0   51852.3   4864.0 3049.8 512.0  321.7      26    0.064   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  62974.4   102400.0   51852.3   4864.0 3049.8 512.0  321.7      26    0.064   2      0.002    0.065
10240.0 10240.0  0.0    0.0   81920.0  10240.0   102400.0   62092.3   4864.0 3049.8 512.0  321.7      27    0.065   2      0.002    0.067
10240.0 10240.0  0.0    0.0   81920.0  32198.7   102400.0   62092.3   4864.0 3049.8 512.0  321.7      27    0.065   2      0.002    0.067
10240.0 10240.0  0.0    0.0   81920.0  52678.7   102400.0   62092.3   4864.0 3049.8 512.0  321.7      27    0.065   2      0.002    0.067
10240.0 10240.0  0.0    0.0   81920.0  73158.7   102400.0   62092.3   4864.0 3049.8 512.0  321.7      27    0.065   2      0.002    0.067
10240.0 10240.0  0.0    0.0   81920.0  22014.5   102400.0   62092.3   4864.0 3050.1 512.0  321.7      28    0.066   2      0.002    0.068
10240.0 10240.0  0.0    0.0   81920.0  42494.6   102400.0   62092.3   4864.0 3050.1 512.0  321.7      28    0.066   2      0.002    0.068
Copy the code

Survivor0/Survivor1 10M, Survivor0/Survivor1 10M, Survivor0/Survivor1 10M, Survivor0 80M, Survivor1 100M

The rate of growth of the new generation of objects

As you can see from the EU line, the new generation is basically growing at around 20M objects per second.

YoungGC Trigger frequency and duration

As can be seen from the memory changes in Eden area, YoungGC will trigger once every 3 or 4 seconds. For example, when Eden area grew to 66424.2 for the first time, only 11878.4 remained after a YoungGC. You can also see the frequency of YoungGC roughly from the YGC column.

As can be seen from the YGCT column, each YoungGC takes 1~5 milliseconds, that is, every 3~4 seconds, the YoungGC system is delayed 1~5 milliseconds. It can also be seen that YoungGC is actually very fast, even if the New generation 800M is only a few milliseconds, which has little impact on the system.

YoungGC specifies the size of the surviving object and how many objects are aged

From the changes of S0U and S1U columns, it can be seen that about 800K objects enter Survivor zone after each YoungGC.

As can be seen from the change of the OU column, the number of objects entering the old age is about 10M each time, so after a YoungGC, there may be 10M surviving objects entering the old age.

How often FullGC triggers and how long it takes

As can be seen from the changes in the OU column, FullGC is triggered when the old age reaches 82573.2, and the size of the old age after recycling is 10892.1. Looking at the overall timeline, it took exactly 60 seconds to trigger a FullGC.

As can be seen from FGCT, a FullGC takes 2 ms:

FullGC was triggered at 82573.2.

As you can see, in this second, the YoungGC actually caused 10M objects to enter the old age, and the old age actually had 92815K objects, so it should have triggered the old age GC after the CMS exceeded the 92% threshold.

Use GCeasy to view GC logs

At this point, you have basically analyzed the entire JVM. Here’s a summary:

New generation and old generation are 100M, Eden area is 80M, Survivor area is 10M;
About 20M objects are generated in Eden area every second. YoungGC is triggered every 3 to 4 seconds.
After YoungGC, the surviving object is about 0~10M. Since the object cannot be placed in the Survivor zone, it will enter the old age, and the object of the old age is about 10M each time.
After about 16 YoungGC times, that is, about 60 seconds, the old age will be close to full and exceed the set threshold, triggering a FullGC.

As you can see from the above analysis, the output of jstat monitoring is basically consistent with the previous estimates. However, a rough estimate requires familiarity with the core business of the system and other unknowns. A rough estimate is usually used to set JVM parameters when the system is just coming online. Monitoring by Jstat generally gives you an accurate picture of how the JVM is performing and can then be tuned for performance.

The GC logs are no longer analyzed line by line. Instead, we use the online tool GCeasy to look at memory changes and GC. Copy the output GC logs directly to GCeasy, and you can see the results of the analysis.

1. General situation of GC

The following information can be obtained from this picture:

The garbage collector throughput rate is 99.937%;
Average GC pause time: 2 ms
Maximum GC pause time: 10 ms
80% of GC takes 0 to 1 ms
The 20% GC takes 9 to 10 milliseconds

2. YoungGC frequency

As you can see from the statistics of Young Gen, the frequency of Young Gen is 3-4 seconds.

3. GC frequency in the old age

In the old age, YoungGC is increased once every two times, with each increase of about 10M. OldGC is triggered once in about 60 seconds.

4. CMS recycling

This chart shows the statistics for each phase of the CMS

Performance optimization

From the above analysis, it can be seen that the biggest problem of this JVM is that the Survivor zone is not working. The Survivor zone is only 10M, but after YoungGC, the survivable object is larger than 10M. Therefore, we can increase the size of the new generation or adjust the ratio between Eden and Survivor to make the object enter the Survivor zone.

For example, change to the following configuration: 150M is given to the new generation, and the ratio is adjusted to 6, so that Eden zone is 90M and Survivor zone is 30M respectively. In this way, Survivor zone is enough for the objects surviving after YoungGC is put down, and dynamic age judgment can basically avoid the objects entering the old age.

-Xms200M
-Xmx200M
-Xmn150M
-XX:SurvivorRatio=6
Copy the code

Look at this moment the GC conditions, begin from S0U, S1U changes can be seen, Survivor area at work, after each YoungGC live objects into the Survivor area.

Then, it can be seen from the changes of OU and YGC that some long-term surviving objects enter the old age after the YoungGC times exceed the set GC age threshold (5 years).

As you can see from the FGC column, no FullGC has occurred after the Survivor zone has been properly set.

Use MAT to analyze OOM problems

The best way to troubleshoot OOM problems and analyze application heap memory usage is to analyze heap dumps, which contain the whole heap scene and thread stack information. This section will look at how to use MAT to analyze OOM problems.

Run the sample program

Prepare the following two test classes:

package com.lyyzoo.test.jvm;

public class OomService {

    private List<String> data = new ArrayList<>();

    public void addData(a) {
        // Keep adding 10KB strings to the same ArrayList
        data.add(IntStream.rangeClosed(1.10 _000)
                .mapToObj(__ -> "A")
                .collect(Collectors.joining(""))); }}Copy the code

package com.lyyzoo.test.jvm;

public class OomMain {
    public static void main(String[] args) {
        OomService service = new OomService();

        while (true) { service.addData(); }}}Copy the code

Set the following JVM parameters:

-Xms200M
-Xmx200M
-Xmn100M
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=./dump.hprof
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-Xloggc:./gc.log
Copy the code

OOM exception reported after running the program:

MAT’s thinking of analyzing OOM problem

For programs running online, if we cannot quickly locate the root of OOM through logs, we can generally use MAT to analyze OOM problems.

When using MAT to analyze OOM problems, the following ideas can generally be followed:

Use the dominant tree function or histogram function to view the types of memory consumption to analyze the probable causes of memory leaks.
Look at the types that consume the most memory, a detailed list of objects, and their chains of references to locate memory leaks.
With the function of viewing object attributes, you can see the values and dependencies of various attributes of the object from the source code, to help us clarify the program logic and parameters;
Auxiliary use check the thread stack to see if the OOM problem is related to multiple threads, and even see the OOM thread abnormal at the last moment in the thread stack.

If a memory snapshot is dumped to a large size, such as several gigabytes, it is important to set the MAT’s memory size (default: 1024 MB) in the configuration file (MemoryAnalyzer.ini) before starting MAT, such as 4 OR 8 GIGABytes.

Overview – Quick analysis of OOM problems

Use MAT to open dump file dump.hprof.

As you can see from the pie chart, there are clearly objects that are taking up a lot of memory, and then by looking at Problem Suspect1, we already showed that the main thread is taking up 99.42% of the memory of the Object via local variables, and it’s the java.lang.object [] array that is taking up a lot of memory.

Also called “Accumulated Objects in Dominator Tree”, the main thread references the OomService object. OomService refers to an ArrayList object, and the ArrayList stores a lot of strings. This is basically the root of the OOM.

Click on See StackTrace to See the thread stack and you can almost locate the problem code.

Histogram – Locate the root

The second button on the toolbar opens the histogram, which is grouped by type, lists how many instances each class has, and how much memory it occupies.

As you can see, the char[] byte array takes up the most memory and has a large number of objects. The second String has a large number of objects (9,791).

Char [] can List all instances of char[] and the entire chain of references for each char[] by clicking on the char[] button and choosing List Objects -> With Incoming References:

Randomly expand a char[], as shown below:

You can see the entire chain of references in the right box, and you can see the internal properties of each instance in the left box.

Char [] = char[] = char[] = char[] = char[]; The String is then referenced by the Object[] array of the ArrayList, indicating that a large number of strings are put into the ArrayList, which in turn is referenced by the Data variable of the OomService. The class that causes OOM is located here.

Retained Heap represents the memory of the Retained object and its associated objects, and Shallow Heap represents the memory of the Retained object. For example, the Data ArrayList object in OomService is only 16 bytes in itself, but all its associated objects take up 130+MB of memory.

If you want to see the full content, right-click Copy->Value and Copy the Value to the clipboard or save it to a file:

Dominant tree – Locate the root

In fact, using histograms to locate OomService has taken some detours. You can click the third button in the toolbar to access the dominance tree. Across the Retained Heap, the page directly lists the objects with the largest memory footprint in reverse order.

OomSerice -> ArrayList -> Object[] -> String -> char[]

Thread stack – Analyzing code

You can click the fifth button on the toolbar to open the threads view to analyze what logic OomService performs. You can see that OomService is a local variable of OomMain, and then OomMain calls the addData method of OomService, and then the addData method should generate a string from Stream and put it into data.

OQL – Query data

Click the fourth button on the toolbar to go to the OQL interface. This interface allows you to search for data in dump using sqL-like syntax. You can see that only one instance of OomService is created, indicating that there is only one place where OomService methods are called.

You can then search for objects that reference OomService using the List Objects function:

You can see that it is referenced by the main thread:

Arthas was used to analyze high CPU problems

Arthas is ali open source Java diagnostic tool, compared with the JDK built-in diagnostic tool, to be more humanization, and powerful, can realize many problems a key position, and can be a key decompiled class view the source code, or even directly hot repair for production code, to achieve within a tool to quickly locate and repair the problem of one-stop service.

Arthas official document: alibaba. Making. IO/Arthas

Run the sample program

Prepare the following cpu-heavy code: create a thread pool of 2 threads and submit a task to encrypt a long string using the BCryptPasswordEncoder, which is CPU intensive.

package com.lyyzoo.test.jvm;

import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
import java.util.stream.Collectors;
import java.util.stream.IntStream;

import org.apache.commons.lang3.RandomUtils;
import org.springframework.security.crypto.bcrypt.BCryptPasswordEncoder;

public class CpuService {
    private BCryptPasswordEncoder encoder = new BCryptPasswordEncoder();
    private ExecutorService executor = Executors.newFixedThreadPool(2);

    public void doTask(a) throws Exception {
        while (true) {
            randomEncode(RandomUtils.nextInt(0.10000)); }}private void randomEncode(Integer size) throws Exception {
        String payload = IntStream.rangeClosed(1, size).mapToObj(__ -> "A").collect(Collectors.joining());
        Future<String> f1 = executor.submit(() -> {
            return encoder.encode(payload);
        });
        Future<String> f2 = executor.submit(() -> {
            returnencoder.encode(payload); }); f1.get(); f2.get(); }}Copy the code

public class CpuMain {
    private static CpuService service = new CpuService();

    public static void main(String[] args) throws Exception { service.doTask(); }}Copy the code

Start the Arthas

First, download Arthas: arthas.aliyun.com/arthas-boot…

Arthas: java-jar arthas-boot.jar

Once started, go directly to the JVM process we want to check and see that the Arthas add-on succeeded:

Enter the help command to see a list of all supported commands. Commands such as dashboard, Thread, jad, and watch are used to locate CPU problems.

Dashboard – Shows the overall picture

The dashboard command shows all the threads, memory, GC, etc. It is obvious that there are two threads with high CPU usage. According to the thread name, they should be threads in the thread pool.

Thread – View threads with high CPUS

Next, you can view the stack of threads executing by the busiest thread, using the thread-n command. CpuService’s randomEncode method calls encode of BCryptPasswordEncoder, which causes the CPU load to be high.

Watch – Monitoring parameters

If you want to observe the incoming and outgoing parameters of a method, you can use the watch command to observe:

Jad – decompile

CpuService’s randomEncode is the highest CPU load in CpuService’s randomEncode.

Define – Reload the class

If we wanted to debug online but didn’t want to change the code locally, print the log, submit to the server, and restart the service test, we could use arthas jad, MC, re-define dynamically.

1. First download the source file using JAD

Then modify the source code: add a line of output log

Decompile source files using MC command

After decompiling, the corresponding class file is generated:

3. Use Re-define to reload the class

The console is already printing the log we printed:

As an additional note, since commands such as Monitor, Trace, watch, etc. are implemented through bytecode enhancement techniques that insert aspects into the methods of the specified class for statistics and observations, diagnosis ends with shutdown to restore the class or method bytecode and exit Arthas.

mo4tech.com (Moment For Technology) is a global community with thousands techies from across the global hang out!Passionate technologists, be it gadget freaks, tech enthusiasts, coders, technopreneurs, or CIOs, you would find them all here.

JVM performance Tuning (6) – Tune analysis problems with tools

Analyze JVM health with tools

Run the sample program

The rate of growth of the new generation of objects

YoungGC Trigger frequency and duration

YoungGC specifies the size of the surviving object and how many objects are aged

How often FullGC triggers and how long it takes

Use GCeasy to view GC logs

Performance optimization

Use MAT to analyze OOM problems

Run the sample program

MAT’s thinking of analyzing OOM problem

Overview – Quick analysis of OOM problems

Histogram – Locate the root

Dominant tree – Locate the root

Thread stack – Analyzing code

OQL – Query data

Arthas was used to analyze high CPU problems

Run the sample program

Start the Arthas

Dashboard – Shows the overall picture

Thread – View threads with high CPUS

Watch – Monitoring parameters

Jad – decompile

Define – Reload the class

JVM performance Tuning (6) – Tune analysis problems with tools

Analyze JVM health with tools

Run the sample program

The rate of growth of the new generation of objects

YoungGC Trigger frequency and duration

YoungGC specifies the size of the surviving object and how many objects are aged

How often FullGC triggers and how long it takes

Use GCeasy to view GC logs

Performance optimization

Use MAT to analyze OOM problems

Run the sample program

MAT’s thinking of analyzing OOM problem

Overview – Quick analysis of OOM problems

Histogram – Locate the root

Dominant tree – Locate the root

Thread stack – Analyzing code

OQL – Query data

Arthas was used to analyze high CPU problems

Run the sample program

Start the Arthas

Dashboard – Shows the overall picture

Thread – View threads with high CPUS

Watch – Monitoring parameters

Jad – decompile

Define – Reload the class

Related Posts

How to unify API interface response format in Spring Boot?

5 minutes to teach you how to create a VIRTUAL machine! Doesn’t it smell good?

Memory overflow or CPU full check (super detailed pit record)