JVM分配大内存情况下FGC情况模拟实验

2021-05-13 6,896
1、测试代码实例:使用线程池不断的创建对象

import java.util.Scanner;

import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

/**
 * @author
 * @Description:XXXXXX
 * @Date: Created in 20:07 2021/1/25
 */
public class Mem {
    private static final ThreadPoolExecutor executor = new ThreadPoolExecutor(32, 32, 60,
            TimeUnit.SECONDS, new ArrayBlockingQueue<>(3), new ThreadPoolExecutor.DiscardOldestPolicy());

    public static void main(String[] args) throws Exception {
        System.out.println("Enter executor num:");
        Scanner scanner = new Scanner(System.in);
        int worker = Integer.valueOf(scanner.next());

        for (int i = 0; i < worker; i++) {
            System.out.println("worker " + i + " start...");
            executor.execute(() -> {
                try {
                    alloc(Integer.MAX_VALUE);
                    Thread.sleep(1);
                } catch (Exception e) {
                }
            });
            System.out.println("worker " + i + " end...");
        }

        System.out.println("End");
    }

    private static void alloc(int n) {
        byte[] block = null;
        for (int i = 0; i < n; i++) {
            //申请512M空间
            block = new byte[512 * 1024 * 1024];
            System.out.println("apply for memory 512M");
        }
    }
}


2、使用的命令说明

a.测试代码执行命令,堆内存18g,使用不同的GC算法


重要参数说明:
-Xms18g -Xmx18g:
-XX:+PrintGC 打印GC日志
-XX:+PrintGCTimeStamps   打印GC发送的时间
-XX:+PrintGCApplicationStoppedTime  打印应用由于GC而产生的停顿时间
-XX:+UseG1GC 指定G1垃圾回收
-XX:+UseConcMarkSweepGC 指定CMS垃圾回收

java -Xms18g -Xmx18g -XX:+UseConcMarkSweepGC -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -Xloggc:cmsgc.log Mem

java -Xms18g -Xmx18g -XX:+UseG1GC -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -Xloggc:g1gc.log Mem

b.GC情况查看命令,间隔10秒,观察30次

jstat -gcutil pid 10000 30

3、服务器配置和实验数据

CPU:Intel(R) Xeon(R) CPU E5-2609 v4 @ 1.70GHz
内存:24G
硬盘:500G
操作系统:centos
jdk:1.8.0_121-b13
堆内存:限制18G
变量:垃圾回收算法(CMS和G1)


使用UseConcMarkSweepGC的GC情况

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00   4.00   0.00  17.28  19.76      0    0.000     0    0.000    0.000
  0.01   0.02  96.19  49.00  91.41  82.79     18    5.350     0    0.000    5.350
  0.00   0.02  96.14  97.99  91.53  82.79     36   12.885     1    0.000   12.885
  0.00   0.00  96.14  97.99  91.55  82.79     60   15.517     4    4.423   19.939
  0.00   0.00  96.14  97.99  91.55  82.79     78   19.744     8    9.090   28.834
  0.00   0.00  96.14  97.99  91.62  82.79     95   21.575    13   15.444   37.019
  0.00   0.00  96.14  97.99  91.62  82.79    108   22.636    17   22.066   44.702
  0.00   0.00  96.14  97.99  91.62  82.79    116   23.245    21   31.244   54.488
  0.00   0.00  96.14  97.99  91.62  82.79    126   23.833    27   39.567   63.399
  0.00   0.00  96.14  97.99  91.62  82.79    136   24.415    33   49.362   73.777
  0.00   0.00  96.14  97.99  91.62  82.79    144   24.891    38   56.471   81.362
  0.00   0.00  96.14  97.99  91.63  82.79    156   25.652    44   66.230   91.882
  0.00   0.00  97.14  97.99  91.84  82.79    164   26.175    48   73.664   99.839
  0.00   0.00  96.14  97.99  91.87  82.79    171   28.897    52   84.253  113.150
  0.00   0.00  96.14  97.99  91.87  82.79    178   29.142    57   93.978  123.120
  0.00   0.00  96.14  97.99  91.87  82.79    186   29.609    62  103.077  132.686
  0.00   0.00  98.14  97.99  91.87  82.79    192   29.990    65  111.313  141.303
  0.00   0.00 100.00  97.99  91.87  82.79    198   30.391    69  120.084  150.474
  0.00   0.00 100.00  97.99  91.87  82.79    209   31.945    75  129.803  161.748
  0.00   0.00  96.14  97.99  91.87  82.79    218   32.546    79  137.913  170.459
  0.00   0.00  96.79  97.99  91.87  82.79    225   33.012    83  145.764  178.776
  0.00   0.00  96.14  95.10  91.87  82.79    233   33.483    88  153.464  186.947
  0.00   0.00  96.14  97.99  91.94  82.79    243   34.094    94  164.024  198.118
  0.00   0.00  96.14  97.99  92.05  82.79    250   34.562    98  171.400  205.962
  0.00   0.00   0.00  95.10  92.05  82.79    256   34.963   101  183.027  217.990
  0.00   0.00  96.14  97.99  92.05  82.79    264   35.467   106  191.465  226.932
  0.00   0.00  96.14  97.99  92.05  82.79    268   37.928   108  197.131  235.059
  0.00   0.00  96.14  97.99  92.05  82.79    276   38.398   113  207.743  246.141
  0.00   0.00  96.56  97.99  92.05  82.79    282   38.766   117  215.147  253.913
  0.00   0.00  96.32  97.99  92.08  82.79    290   39.229   121  223.913  263.142


使用G1的GC情况

 S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00   0.00   0.00  17.28  19.76      0    0.000     0    0.000    0.000
  0.00 100.00   0.00  99.96  91.64  82.79     27    0.136     0    0.000    0.136
  0.00   0.00   0.00  99.96  92.09  82.79    134    0.440     0    0.000    0.440
  0.00   0.00   0.00  99.96  92.09  82.79    240    0.775     0    0.000    0.775
  0.00   0.00   0.00  99.96  92.09  82.79    347    1.085     0    0.000    1.085
  0.00   0.00   0.00  99.96  92.09  82.79    422    1.413     0    0.000    1.413
  0.00   0.00   0.00  93.82  92.46  82.84    495    1.765    22    2.339    4.104
  0.00   0.00   0.00  96.75  92.47  82.84    570    1.982    66    6.656    8.639
  0.00   0.00   0.00  96.75  92.47  82.84    624    2.213   103   10.610   12.822
  0.00   0.00   0.83  96.71  92.47  82.84    668    2.505   135   16.130   18.635
  0.00   0.00   0.00  96.75  92.47  82.84    718    3.932   173   20.356   24.288
  0.00   0.00   0.00  97.06  92.59  82.99    785    4.169   214   24.755   28.924
  0.00   0.00   0.83  96.71  92.59  82.99    849    4.406   232   26.653   31.059
  0.00   0.00   0.83  99.64  92.59  82.99    925    4.696   233   26.753   31.449
  0.00 100.00   0.78  99.96  92.59  82.99    992    4.915   238   27.267   32.182
  0.00   0.00   1.65  99.64  92.59  82.99   1049    5.109   247   28.205   33.315
  0.00   0.00   1.56  99.96  92.59  82.99   1115    5.358   249   28.411   33.769
  0.00   0.00   1.59  99.96  92.59  82.99   1174    5.576   250   28.513   34.089
  0.00   0.00   1.56  99.96  92.59  82.99   1227    5.774   256   29.145   34.918
  0.00   0.00   1.56  99.96  92.59  82.99   1283    5.964   261   29.665   35.629
  0.00   0.00   1.56  99.96  92.59  82.99   1340    6.162   262   29.768   35.931
  0.00   0.00   0.00  99.96  92.59  82.99   1399    6.377   264   29.979   36.356
  0.00   0.00   0.00  99.96  92.59  82.99   1456    6.598   267   30.187   36.785
  0.00   0.00   1.56  99.96  92.59  82.99   1515    6.796   268   30.393   37.190
  0.00   0.00   1.56  99.96  92.59  82.99   1577    7.033   270   30.598   37.631
  0.00   0.00   0.00  99.96  92.59  82.99   1639    7.253   272   30.806   38.059
  0.00   0.00   1.56  99.96  92.59  82.99   1699    7.483   274   31.015   38.497
  0.00   0.00   1.56  99.96  92.59  82.99   1752    7.668   278   31.425   39.093
  0.00   0.00   1.56  99.96  92.59  82.99   1803    7.864   281   31.731   39.595
  0.00   0.00   1.59  99.96  92.59  82.99   1850    8.033   286   32.271   40.304


使用CMS的应用暂停时间(选取部分)

491.172: [Full GC (Allocation Failure) 18350819K->17302210K(18806272K), 2.7447486 secs]
493.961: Total time for which application threads were stopped: 2.8691817 seconds, Stopping threads took: 0.0795971 seconds
494.041: [GC (Allocation Failure) 17826909K->17826500K(18806272K), 0.1132958 secs]
494.154: Total time for which application threads were stopped: 0.1934281 seconds, Stopping threads took: 0.0798435 seconds
494.239: [Full GC (Allocation Failure) 18351199K->17302210K(18806272K), 2.6556058 secs]
496.938: Total time for which application threads were stopped: 2.7832497 seconds, Stopping threads took: 0.0830667 seconds
497.018: [GC (Allocation Failure) 17826765K->17826500K(18806272K), 0.1161283 secs]
497.134: Total time for which application threads were stopped: 0.1962357 seconds, Stopping threads took: 0.0798200 seconds
497.215: [Full GC (Allocation Failure) 18350962K->17302210K(18806272K), 1.3247983 secs]
498.583: Total time for which application threads were stopped: 1.4485793 seconds, Stopping threads took: 0.0789361 seconds
498.666: [GC (Allocation Failure) 17826498K->17826500K(18806272K), 0.1134047 secs]
498.779: Total time for which application threads were stopped: 0.1967264 seconds, Stopping threads took: 0.0830367 seconds
498.861: [Full GC (Allocation Failure) 18350882K->17302210K(18806272K), 1.4982433 secs]
500.403: Total time for which application threads were stopped: 1.6238582 seconds, Stopping threads took: 0.0797511 seconds
500.485: [GC (Allocation Failure) 17826498K->17826500K(18806272K), 0.1272701 secs]
500.612: Total time for which application threads were stopped: 0.2085994 seconds, Stopping threads took: 0.0809783 seconds
500.697: [Full GC (Allocation Failure) 18350801K->17826498K(18806272K), 0.5578431 secs]
501.304: Total time for which application threads were stopped: 0.6919552 seconds, Stopping threads took: 0.0837865 seconds
501.395: [Full GC (Allocation Failure) 18371842K->17302211K(18806272K), 2.6491250 secs]
504.090: Total time for which application threads were stopped: 2.7847448 seconds, Stopping threads took: 0.0892144 seconds
504.170: [GC (Allocation Failure) 17837454K->17826507K(18806272K), 1.2969435 secs]
505.499: Total time for which application threads were stopped: 1.4089028 seconds, Stopping threads took: 0.0793611 seconds
505.592: [Full GC (Allocation Failure) 18355521K->17302212K(18806272K), 2.8537842 secs]


使用G1的应用暂停时间(选取部分)

9.938: [GC pause (G1 Humongous Allocation) (young) (initial-mark) 16G->16G(18G), 0.0074400 secs]
89.946: [GC concurrent-root-region-scan-start]
89.946: [GC concurrent-root-region-scan-end, 0.0000230 secs]
89.946: [GC concurrent-mark-start]
89.946: Total time for which application threads were stopped: 0.0913843 seconds, Stopping threads took: 0.0836821 seconds
89.949: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0024211 secs]
89.951: Total time for which application threads were stopped: 0.0029560 seconds, Stopping threads took: 0.0000470 seconds
89.954: [GC concurrent-mark-end, 0.0077998 secs]
90.032: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0030254 secs]
90.035: Total time for which application threads were stopped: 0.0808401 seconds, Stopping threads took: 0.0769236 seconds
90.036: [Full GC (Allocation Failure) 16G->16G(18G), 0.1000621 secs]
90.136: Total time for which application threads were stopped: 0.1007767 seconds, Stopping threads took: 0.0000808 seconds
90.224: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0028310 secs]
90.227: Total time for which application threads were stopped: 0.0905506 seconds, Stopping threads took: 0.0869216 seconds
90.227: [Full GC (Allocation Failure) 16G->16G(18G), 0.1026309 secs]
90.330: Total time for which application threads were stopped: 0.1032992 seconds, Stopping threads took: 0.0000372 seconds
90.414: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0047862 secs]
90.419: Total time for which application threads were stopped: 0.0862279 seconds, Stopping threads took: 0.0806315 seconds
90.419: [Full GC (Allocation Failure) 16G->16G(18G), 0.1011580 secs]
90.521: Total time for which application threads were stopped: 0.1018183 seconds, Stopping threads took: 0.0000429 seconds
90.603: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0043945 secs]
90.607: Total time for which application threads were stopped: 0.0854959 seconds, Stopping threads took: 0.0803917 seconds
90.608: [Full GC (Allocation Failure) 16G->16G(18G), 0.1055658 secs]
90.714: Total time for which application threads were stopped: 0.1061946 seconds, Stopping threads took: 0.0000364 seconds
90.794: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0030520 secs]
90.798: Total time for which application threads were stopped: 0.0836833 seconds, Stopping threads took: 0.0799108 seconds
90.798: [Full GC (Allocation Failure) 16G->16G(18G), 0.0975948 secs]
90.896: [Full GC (Allocation Failure) 16G->16G(18G), 0.0983627 secs]
90.994: Total time for which application threads were stopped: 0.1967194 seconds, Stopping threads took: 0.0000412 seconds
90.997: [GC pause (G1 Humongous Allocation) (young) 16G->15G(18G), 0.0028386 secs]
91.000: Total time for which application threads were stopped: 0.0034994 seconds, Stopping threads took: 0.0000583 seconds
91.099: [GC pause (G1 Humongous Allocation) (young) 16G->16G(18G), 0.0023358 secs]
91.101: Total time for which application threads were stopped: 0.0991074 seconds, Stopping threads took: 0.0961578 seconds


4、结论

CMS

G1

YGC(年轻代GC次数)

290

1850

YGCT(年轻代GC的时间)

39.229

8.033s

FGC(FullGC的次数)

121

286

FGCT(FullGC的总时间)

223.913s

32.271s

GCT(GC的总时间)

263.142s

40.304s

最大应用暂停时间

2.869s

0.196s


CMS垃圾回收产生的FullGC次数是121,FullGC总的时间是223.913s,平均每次FullGC的时间是1.85s,总的GC时间是263.142s


G1垃圾回收产生的FullGC次数是286,FullGC总的时间是32.271s,平均每次FullGC的时间是0.11s,总的GC时间是40.304s


显然在实验中,G1总的GC时间短,FullGC的次数是CMS的2.36倍,CMS应用暂停时间达到最大2.869s,G1最大应用暂停时间0.196s,也跟官方给FGC的最大暂停时间(200ms)接近G1算法已经称为Java8之后的默认算法,本身的需要调整的参数很少,性能&易用性方面都比CMS好。大内存的情况下,同等条件,G1算法比CMS更适合


5、参考文档

https://www.oracle.com/cn/technical-resources/articles/java/g1gc.html
https://www.oracle.com/technetwork/tutorials/tutorials-1876574.html


Recommended Use Cases for G1

The first focus of G1 is to provide a solution for users running applications that require large heaps with limited GC latency. This means heap sizes of around 6GB or larger, and stable and predictable pause time below 0.5 seconds.

Applications running today with either the CMS or the ParallelOldGC garbage collector would benefit switching to G1 if the application has one or more of the following traits.

– Full GC durations are too long or too frequent.

– The rate of object allocation rate or promotion varies significantly.

– Undesired long garbage collection or compaction pauses (longer than 0.5 to 1 second)

Note: If you are using CMS or ParallelOldGC and your application is not experiencing long garbage collection pauses, it is fine to stay with your current collector. Changing to the G1 collector is not a requirement for using the latest JDK.


以下是对oracle官方描述的翻译

G1的推荐用例

G1的首要重点是为运行需要大量GC延迟的应用程序的用户提供一个解决方案。这意味着堆大小约为6GB或更大,并且稳定且可预测的暂停时间低于0.5秒。

如果应用程序具有以下一个或多个特性,那么使用CMS或ParallelOldGC垃圾收集器运行的应用程序将有利于切换到G1。

• Full GC 持续时间太长或太频繁

• 对象分配频率高或者提升变化明显

• 不期望GC久、压缩停顿 (超过 0.5 to 1 秒)

注意:如果您使用的是CMS或parallelloldgc,并且您的应用程序没有遇到长时间的垃圾收集暂停,那么可以使用当前收集器。使用最新的JDK不需要更改为G1收集器。


本文作者:安全狗

本文为安全脉搏专栏作者发布,转载请注明:https://www.secpulse.com/archives/158874.html

Tags:
评论  (0)
快来写下你的想法吧!

安全狗

文章数:24 积分: 180

基于智能驱动的新一代云安全公司

安全问答社区

安全问答社区

脉搏官方公众号

脉搏公众号