Shulou(Shulou.com)06/01 Report--

This article will explain in detail how to solve the problem of printing GC logs. The content of the article is of high quality, so the editor will share it with you for reference. I hope you will have a certain understanding of the relevant knowledge after reading this article.

In our work, sometimes we need to print information about GC to locate the problem. What should be done?

Let's take a look at an example.

Public static void main (String [] args) {

List list0 = new ArrayList ()

Long start0 = System.currentTimeMillis ()

For (int I = 0; I

< 1000000; i++) { list0.add(i); } System.out.println("cost: " + (System.currentTimeMillis() - start0)); List list1 = new ArrayList(); long start1 = System.currentTimeMillis(); for (int i = 0; i < 1000000; i++) { list1.add(i); } System.out.println("cost: " + (System.currentTimeMillis() - start1)); } 直接运行，结果如下， cost: 135 cost: 85 你应该觉得奇怪，同样的往一个list插入100万条数据，为啥第一个耗时比较久？ 这种时候，有经验的工程师应该能马上怀疑是GC的问题，我们可以通过在运行时添加JVM参数来打印程序运行时的GC情况。 -XX:+PrintGCDetails 如果是使用IDEA来运行，可以在 run configurations 的 VM options添加上面的参数即可。 再次运行，输出如下， [GC (Allocation Failure) [PSYoungGen: 1536K->

512K (1536K)] 1884K-> 1234K (262144K), 0.0009030 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]

[GC (Allocation Failure) [PSYoungGen: 1302K-> 1017K (2560K)] 2025K-> 1948K (263168K), 0.0012290 secs] [Times: user=0.01 sys=0.01, real=0.01 secs]

[GC (Allocation Failure) [PSYoungGen: 2553K-> 1504K (3072K)] 3484K-> 3051K (263680K), 0.0017210 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]

[GC (Allocation Failure) [PSYoungGen: 3040K-> 2033K (4608K)] 4587K-> 4228K (265216K), 0.0023170 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]

[GC (Allocation Failure) [PSYoungGen: 4593K-> 2560K (5120K)] 8195K-> 6681K (265728K), 0.0249700 secs] [Times: user=0.31 sys=0.00, real=0.03 secs]

[GC (Allocation Failure) [PSYoungGen: 5120K-> 3584K (6656K)] 11352K-> 11408K (267264K), 0.0241680 secs] [Times: user=0.30 sys=0.01, real=0.03 secs]

[GC (Allocation Failure) [PSYoungGen: 6656K-> 3296K (7680K)] 17645K-> 17909K (268288K), 0.0349010 secs] [Times: user=0.45 sys=0.00, real=0.03 secs]

[GC (Allocation Failure) [PSYoungGen: 6368K-> 3328K (10240K)] 25729K-> 25825K (270848K), 0.0314260 secs] [Times: user=0.40 sys=0.00, real=0.03 secs]

Cost: 137

[GC (Allocation Failure) [PSYoungGen: 8166K-> 4469K (10240K)] 30663K-> 30103K (270848K), 0.0285370 secs] [Times: user=0.36 sys=0.01, real=0.03 secs]

[GC (Allocation Failure) [PSYoungGen: 9166K-> 3785K (13312K)] 34800K-> 33427K (273920K), 0.0226780 secs] [Times: user=0.28 sys=0.01, real=0.02 secs]

[GC (Allocation Failure) [PSYoungGen: 11465K-> 6142K (13824K)] 41107K-> 38511K (274432K), 0.0065540 secs] [Times: user=0.08 sys=0.00, real=0.00 secs]

[GC (Allocation Failure) [PSYoungGen: 13822K-> 7837K (19456K)] 46191K-> 44246K (280064K), 0.0099720 secs] [Times: user=0.11 sys=0.01, real=0.01 secs]

Cost: 79

So you probably understand that the first minor gc takes more times than the second, so it takes a long time to run.

So what exactly does the log printed above mean? Someone has already drawn a very detailed picture. I'll borrow it.

Know how to print GC logs, and be able to read GC logs, which is very helpful to find location problems.

I have encountered a situation where the last CPU in production reached hundreds of times. Printing the GC log found that the JVM had been in fullGC all the time, and the memory had not changed after each GC, thus locating the possible memory leak in the application.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.