devbox
我家自动化
这个屌丝很懒，什么也没留下！
关注作者
热门标签
热门文章
当前位置:   article > 正文

阿里巴巴Arthas分析调优JVM实战及常量池详解_阿里jvm调优工具

作者：我家自动化 | 2024-08-18 00:24:51

赞

踩

阿里jvm调优工具

目录

一、阿里巴巴Arthas详解

Arthas使用场景

Arthas命令

Arthas使用

二、GC日志详解

如何分析GC日志

CMS

G1

GC日志分析工具

三、JVM参数汇总查看命令

四、Class常量池与运行时常量池

字面量

符号引用

五、字符串常量池

字符串常量池的设计思想

三种字符串操作(jdk1.7 及以上版本)

字符串常量池位置

字符串常量池设计原理

String常量池问题的几个例子

关于String是不可变的

六、八种基本类型的包装类和对象池

一、阿里巴巴Arthas详解

Arthas 是 Alibaba 在 2018 年 9 月开源的 Java 诊断工具。支持 JDK6+， 采用命令行交互模式，可以方便的定位和诊断线上程序运行问题。Arthas 官方文档十分详细。

由于 Arthas 是用 Java 编写的，因此它是跨平台的，可以在 Linux、macOS 和 Windows 上运行。

详见：简介 | arthas (aliyun.com)

Arthas使用场景

得益于 Arthas 强大且丰富的功能，让 Arthas 能做的事情超乎想象。下面仅仅列举几项常见的使用情况，更多的使用场景可以在熟悉了 Arthas 之后自行探索。

  1. 是否有一个全局视角来查看系统的运行状况？
  2. 为什么 CPU 又升高了，到底是哪里占用了 CPU ？
  3. 运行的多线程有死锁吗？有阻塞吗？
  4. 程序运行耗时很长，是哪里耗时比较长呢？如何监测呢？
  5. 这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？
  6. 我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？
  7. 遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？
  8. 有什么办法可以监控到 JVM 的实时运行状态？

Arthas命令

这里仅列举部门命令，其它命令请详见官网：命令列表 | arthas (aliyun.com)

jvm 相关

  • dashboard - 当前系统的实时数据面板
  • getstatic - 查看类的静态属性
  • heapdump - dump java heap, 类似 jmap 命令的 heap dump 功能
  • jvm - 查看当前 JVM 的信息
  • logger - 查看和修改 logger
  • mbean - 查看 Mbean 的信息
  • memory - 查看 JVM 的内存信息
  • ognl - 执行 ognl 表达式
  • perfcounter - 查看当前 JVM 的 Perf Counter 信息
  • sysenv - 查看 JVM 的环境变量
  • sysprop - 查看和修改 JVM 的系统属性
  • thread - 查看当前 JVM 的线程堆栈信息
  • vmoption - 查看和修改 JVM 里诊断相关的 option
  • vmtool - 从 jvm 里查询对象，执行 forceGc

基础命令

  • base64 - base64 编码转换，和 linux 里的 base64 命令类似
  • cat - 打印文件内容，和 linux 里的 cat 命令类似
  • cls - 清空当前屏幕区域
  • echo - 打印参数，和 linux 里的 echo 命令类似
  • grep - 匹配查找，和 linux 里的 grep 命令类似
  • help - 查看命令帮助信息
  • history - 打印命令历史
  • keymap - Arthas 快捷键列表及自定义快捷键
  • pwd - 返回当前的工作目录，和 linux 命令类似
  • quit - 退出当前 Arthas 客户端，其他 Arthas 客户端不受影响
  • reset - 重置增强类，将被 Arthas 增强过的类全部还原，Arthas 服务端关闭时会重置所有增强过的类
  • session - 查看当前会话的信息
  • stop - 关闭 Arthas 服务端，所有 Arthas 客户端全部退出
  • tee - 复制标准输入到标准输出和指定的文件，和 linux 里的 tee 命令类似
  • version - 输出当前目标 Java 进程所加载的 Arthas 版本号

Arthas使用

  1. # github下载arthas
  2. wget https://alibaba.github.io/arthas/arthas-boot.jar
  3. # 或者 Gitee 下载
  4. wget https://arthas.gitee.io/arthas-boot.jar

用java -jar运行即可，可以识别机器上所有Java进程(我们这里之前已经运行了一个Arthas测试程序，代码见下方)

  1. package com.study.jvm;
  2.  
  3. import java.util.HashSet;
  4.  
  5. public class Arthas {
  6.     private static HashSet hashSet = new HashSet();
  7.  
  8.     public static void main(String[] args) {
  9.         // 模拟 CPU 过高
  10.         cpuHigh();
  11.         // 模拟线程死锁
  12.         deadThread();
  13.         // 不断的向 hashSet 集合增加数据
  14.         addHashSetThread();
  15.     }
  16.  
  17.     /**
  18.      * 不断的向 hashSet 集合添加数据
  19.      */
  20.     public static void addHashSetThread() {
  21.         // 初始化常量
  22.         new Thread(() -> {
  23.             int count = 0;
  24.             while (true) {
  25.                 try {
  26.                     hashSet.add("count" + count);
  27.                     Thread.sleep(1000);
  28.                     count++;
  29.                 } catch (InterruptedException e) {
  30.                     e.printStackTrace();
  31.                 }
  32.             }
  33.         }).start();
  34.     }
  35.  
  36.     public static void cpuHigh() {
  37.         new Thread(() -> {
  38.             while (true) {
  39.  
  40.             }
  41.         }).start();
  42.     }
  43.  
  44.     /**
  45.      * 死锁
  46.      */
  47.     private static void deadThread() {
  48.         /** 创建资源 */
  49.         Object resourceA = new Object();
  50.         Object resourceB = new Object();
  51.         // 创建线程
  52.         Thread threadA = new Thread(() -> {
  53.             synchronized (resourceA) {
  54.                 System.out.println(Thread.currentThread() + " get ResourceA");
  55.                 try {
  56.                     Thread.sleep(1000);
  57.                 } catch (InterruptedException e) {
  58.                     e.printStackTrace();
  59.                 }
  60.                 System.out.println(Thread.currentThread() + "waiting get resourceB");
  61.                 synchronized (resourceB) {
  62.                     System.out.println(Thread.currentThread() + " get resourceB");
  63.                 }
  64.             }
  65.         });
  66.  
  67.         Thread threadB = new Thread(() -> {
  68.             synchronized (resourceB) {
  69.                 System.out.println(Thread.currentThread() + " get ResourceB");
  70.                 try {
  71.                     Thread.sleep(1000);
  72.                 } catch (InterruptedException e) {
  73.                     e.printStackTrace();
  74.                 }
  75.                 System.out.println(Thread.currentThread() + "waiting get resourceA");
  76.                 synchronized (resourceA) {
  77.                     System.out.println(Thread.currentThread() + " get resourceA");
  78.                 }
  79.             }
  80.         });
  81.         threadA.start();
  82.         threadB.start();
  83.     }
  84. }

选择进程序号2，进入进程信息操作

输入help获取查看命令

输入dashboard可以查看整个进程的运行情况，线程、内存、GC、运行环境信息(数据实时更新)：

输入thread可以查看线程详细情况

输入 thread加上线程ID 可以查看线程堆栈

输入 thread -b 可以查看线程死锁

输入 jad加类的全名 可以反编译，这样可以方便我们查看线上代码是否是正确的版本

使用 ognl 命令可以 查看线上系统的变量，甚至可以修改变量的值

修改值需要接引号

更多命令使用可以用help命令查看，或查看官方文档：命令列表 | arthas (aliyun.com)

二、GC日志详解

 对GC垃圾收集器CMS、G1不了解的可参考：JVM垃圾收集器Serial、Parallel Scavenge、ParNew、CMS、G1、ZGC详解-CSDN博客

对于java应用我们可以通过一些配置把程序运行过程中的gc日志全部打印出来，然后分析gc日志得到关键性指标，分析GC原因，调优JVM参数。

打印GC日志方法，在JVM参数里增加参数，%t 代表时间，-XX:+PrintGCCause GC原因，分10个文件，每个文件100M,写满了会循环覆盖

  1. -Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps  -XX:+PrintGCTimeStamps -XX:+PrintGCCause  
  2. -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M

Tomcat则直接加在JAVA_OPTS变量里。

如何分析GC日志

运行程序加上对应gc日志

  1. java -jar -Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps  -XX:+PrintGCTimeStamps -XX:+PrintGCCause  
  2. -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M microservice-eureka-server.jar

截取的JVM刚启动的一部分GC日志

可以看到图中第一行红框，是项目的配置参数。这里不仅配置了打印GC日志，还有相关的VM内存参数。

第二行红框中的是在这个GC时间点发生GC之后相关GC情况。

1、 [PSYoungGen: 261632K->5614K(305152K)] 这三个数字分别对应GC之前占用年轻代的大小，GC之后年轻代占用，以及整个年轻代的大小。

2、271288K->15279K(757760K)这三个数字分别对应GC之前占用堆内存的大小，GC之后堆内存占用，以及整个堆内存的大小。

第三行红框中的是在这个GC时间点发生GC之后相关GC情况。

1、对于2.459： 这是从jvm启动开始计算到这次GC经过的时间，前面还有具体的发生时间日期。

2、Full GC(Metadata GC Threshold)指这是一次full gc，括号里是gc的原因， PSYoungGen是年轻代的GC，ParOldGen是老年代的GC，Metaspace是元空间的GC

3、[PSYoungGen: 16590K->0K(427008K)]，这三个数字分别对应GC之前占用年轻代的大小，GC之后年轻代占用，以及整个年轻代的大小。

4、[ParOldGen: 13007K->22506K(697856K)]，这三个数字分别对应GC之前占用老年代的大小，GC之后老年代占用，以及整个老年代的大小。

5、29597K->22506K(1124864K)，这三个数字分别对应GC之前占用堆内存的大小，GC之后堆内存占用，以及整个堆内存的大小。

6、[Metaspace: 34825K->34825K(1081344K)]，这三个数字分别对应GC之前占用元空间内存的大小，GC之后元空间内存占用，以及整个元空间内存的大小。

7、0.0361425是该时间点GC总耗费时间。

从日志可以发现几次fullgc都是由于元空间不够导致的，所以我们可以将元空间调大点

  1. java -jar -Xloggc:./gc-adjust-%t.log -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps  
  2. -XX:+PrintGCTimeStamps -XX:+PrintGCCause  -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M microservice-eureka-server.jar

调整完我们再看下gc日志发现已经没有因为元空间不够导致的fullgc了

对于CMS和G1收集器的日志会有一点不一样，也可以试着打印下对应的gc日志分析下，可以发现gc日志里面的gc步骤跟我们之前讲过的步骤是类似的

  1. public class HeapTest {
  2.  
  3.     byte[] a = new byte[1024 * 100];  //100KB
  4.  
  5.     public static void main(String[] args) throws InterruptedException {
  6.         ArrayList<HeapTest> heapTests = new ArrayList<>();
  7.         while (true) {
  8.             heapTests.add(new HeapTest());
  9.             Thread.sleep(10);
  10.         }
  11.     }
  12. }

CMS

  1. -Xloggc:d:/gc-cms-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps  
  2. -XX:+PrintGCTimeStamps -XX:+PrintGCCause  -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M 
  3. -XX:+UseParNewGC -XX:+UseConcMarkSweepGC   

  1. Java HotSpot(TM) 64-Bit Server VM (25.333-b02) for windows-amd64 JRE (1.8.0_333-b02), built on Apr 25 2022 22:49:11 by "java_re" with MS VC++ 15.9 (VS2017)
  2. Memory: 4k page, physical 66891640k(45889116k free), swap 71085944k(46785224k free)
  3. CommandLine flags: -XX:CompressedClassSpaceSize=260046848 -XX:GCLogFileSize=104857600 -XX:InitialHeapSize=52428800 -XX:MaxHeapSize=52428800 -XX:MaxMetaspaceSize=268435456 -XX:MaxNewSize=17477632 -XX:MaxTenuringThreshold=6 -XX:MetaspaceSize=268435456 -XX:NewSize=17477632 -XX:NumberOfGCLogFiles=10 -XX:OldPLABSize=16 -XX:OldSize=34951168 -XX:+PrintGC -XX:+PrintGCCause -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseGCLogFileRotation -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
  4. 2023-07-16T00:33:41.624+0800: 1.566: [GC (Allocation Failure) 2023-07-16T00:33:41.624+0800: 1.566: [ParNew: 13647K->1664K(15360K), 0.0035979 secs] 13647K->10728K(49536K), 0.0037244 secs] [Times: user=0.00 sys=0.02, real=0.00 secs] 
  5. 2023-07-16T00:33:43.744+0800: 3.686: [GC (Allocation Failure) 2023-07-16T00:33:43.744+0800: 3.686: [ParNew: 15311K->1568K(15360K), 0.0038323 secs] 24376K->24495K(49536K), 0.0038874 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  6. 2023-07-16T00:33:43.748+0800: 3.690: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22926K(34176K)] 24595K(49536K), 0.0002317 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  7. 2023-07-16T00:33:43.748+0800: 3.691: [CMS-concurrent-mark-start]
  8. 2023-07-16T00:33:43.749+0800: 3.691: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  9. 2023-07-16T00:33:43.749+0800: 3.691: [CMS-concurrent-preclean-start]
  10. 2023-07-16T00:33:43.749+0800: 3.691: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  11. 2023-07-16T00:33:43.749+0800: 3.691: [GC (CMS Final Remark) [YG occupancy: 1668 K (15360 K)]2023-07-16T00:33:43.749+0800: 3.691: [Rescan (parallel) , 0.0002622 secs]2023-07-16T00:33:43.750+0800: 3.692: [weak refs processing, 0.0000100 secs]2023-07-16T00:33:43.750+0800: 3.692: [class unloading, 0.0001797 secs]2023-07-16T00:33:43.750+0800: 3.692: [scrub symbol table, 0.0002542 secs]2023-07-16T00:33:43.750+0800: 3.692: [scrub string table, 0.0000898 secs][1 CMS-remark: 22926K(34176K)] 24595K(49536K), 0.0008292 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  12. 2023-07-16T00:33:43.750+0800: 3.692: [CMS-concurrent-sweep-start]
  13. 2023-07-16T00:33:43.750+0800: 3.693: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  14. 2023-07-16T00:33:43.750+0800: 3.693: [CMS-concurrent-reset-start]
  15. 2023-07-16T00:33:43.750+0800: 3.693: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  16. 2023-07-16T00:33:45.756+0800: 5.698: [GC (CMS Initial Mark) [1 CMS-initial-mark: 22925K(34176K)] 37651K(49536K), 0.0002886 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  17. 2023-07-16T00:33:45.756+0800: 5.698: [CMS-concurrent-mark-start]
  18. 2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  19. 2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-preclean-start]
  20. 2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  21. 2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-abortable-preclean-start]
  22. 2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  23. 2023-07-16T00:33:45.757+0800: 5.699: [GC (CMS Final Remark) [YG occupancy: 14725 K (15360 K)]2023-07-16T00:33:45.757+0800: 5.699: [Rescan (parallel) , 0.0002721 secs]2023-07-16T00:33:45.757+0800: 5.700: [weak refs processing, 0.0000067 secs]2023-07-16T00:33:45.757+0800: 5.700: [class unloading, 0.0001883 secs]2023-07-16T00:33:45.757+0800: 5.700: [scrub symbol table, 0.0002701 secs]2023-07-16T00:33:45.758+0800: 5.700: [scrub string table, 0.0000887 secs][1 CMS-remark: 22925K(34176K)] 37651K(49536K), 0.0008537 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  24. 2023-07-16T00:33:45.758+0800: 5.700: [CMS-concurrent-sweep-start]
  25. 2023-07-16T00:33:45.758+0800: 5.701: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  26. 2023-07-16T00:33:45.758+0800: 5.701: [CMS-concurrent-reset-start]
  27. 2023-07-16T00:33:45.758+0800: 5.701: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  28. 2023-07-16T00:33:45.804+0800: 5.746: [GC (Allocation Failure) 2023-07-16T00:33:45.805+0800: 5.747: [ParNew: 15199K->15199K(15360K), 0.0000197 secs]2023-07-16T00:33:45.805+0800: 5.747: [CMS: 22919K->34088K(34176K), 0.0082704 secs] 38119K->37591K(49536K), [Metaspace: 3817K->3817K(1056768K)], 0.0094345 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
  29. 2023-07-16T00:33:45.813+0800: 5.756: [GC (CMS Initial Mark) [1 CMS-initial-mark: 34088K(34176K)] 37691K(49536K), 0.0005067 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  30. 2023-07-16T00:33:45.814+0800: 5.756: [CMS-concurrent-mark-start]
  31. 2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  32. 2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-preclean-start]
  33. 2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  34. 2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-abortable-preclean-start]
  35. 2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  36. 2023-07-16T00:33:45.814+0800: 5.757: [GC (CMS Final Remark) [YG occupancy: 3864 K (15360 K)]2023-07-16T00:33:45.814+0800: 5.757: [Rescan (parallel) , 0.0003770 secs]2023-07-16T00:33:45.815+0800: 5.758: [weak refs processing, 0.0000063 secs]2023-07-16T00:33:45.815+0800: 5.758: [class unloading, 0.0001777 secs]2023-07-16T00:33:45.815+0800: 5.758: [scrub symbol table, 0.0002964 secs]2023-07-16T00:33:45.815+0800: 5.758: [scrub string table, 0.0000809 secs][1 CMS-remark: 34088K(34176K)] 37953K(49536K), 0.0009690 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  37. 2023-07-16T00:33:45.815+0800: 5.758: [CMS-concurrent-sweep-start]
  38. 2023-07-16T00:33:45.816+0800: 5.758: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  39. 2023-07-16T00:33:45.816+0800: 5.758: [CMS-concurrent-reset-start]
  40. 2023-07-16T00:33:45.816+0800: 5.758: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  41. 2023-07-16T00:33:47.644+0800: 7.586: [GC (Allocation Failure) 2023-07-16T00:33:47.644+0800: 7.586: [ParNew: 15266K->15266K(15360K), 0.0000120 secs]2023-07-16T00:33:47.644+0800: 7.586: [CMS: 34088K->34087K(34176K), 0.0027668 secs] 49354K->49295K(49536K), [Metaspace: 3817K->3817K(1056768K)], 0.0028317 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  42. 2023-07-16T00:33:47.647+0800: 7.589: [Full GC (Allocation Failure) 2023-07-16T00:33:47.647+0800: 7.589: [CMS: 34087K->34135K(34176K), 0.0055808 secs] 49295K->49244K(49536K), [Metaspace: 3817K->3817K(1056768K)], 0.0056079 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
  43. 2023-07-16T00:33:47.653+0800: 7.595: [GC (CMS Initial Mark) [1 CMS-initial-mark: 34135K(34176K)] 49344K(49536K), 0.0002429 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  44. 2023-07-16T00:33:47.653+0800: 7.595: [CMS-concurrent-mark-start]
  45. 2023-07-16T00:33:47.653+0800: 7.595: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  46. 2023-07-16T00:33:47.653+0800: 7.595: [CMS-concurrent-preclean-start]
  47. 2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  48. 2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-abortable-preclean-start]
  49. 2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  50. 2023-07-16T00:33:47.654+0800: 7.596: [GC (CMS Final Remark) [YG occupancy: 15208 K (15360 K)]2023-07-16T00:33:47.654+0800: 7.596: [Rescan (parallel) , 0.0003059 secs]2023-07-16T00:33:47.654+0800: 7.596: [weak refs processing, 0.0000073 secs]2023-07-16T00:33:47.654+0800: 7.596: [class unloading, 0.0001093 secs]2023-07-16T00:33:47.654+0800: 7.596: [scrub symbol table, 0.0001643 secs]2023-07-16T00:33:47.654+0800: 7.596: [scrub string table, 0.0000687 secs][1 CMS-remark: 34135K(34176K)] 49344K(49536K), 0.0006796 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  51. 2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-sweep-start]
  52. 2023-07-16T00:33:47.655+0800: 7.597: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  53. 2023-07-16T00:33:47.655+0800: 7.597: [CMS-concurrent-reset-start]
  54. 2023-07-16T00:33:47.655+0800: 7.597: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  55. 2023-07-16T00:33:47.676+0800: 7.618: [GC (Allocation Failure) 2023-07-16T00:33:47.676+0800: 7.618: [ParNew: 15208K->15208K(15360K), 0.0000098 secs]2023-07-16T00:33:47.676+0800: 7.618: [CMS: 34135K->34135K(34176K), 0.0014248 secs] 49344K->49344K(49536K), [Metaspace: 3817K->3817K(1056768K)], 0.0014718 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  56. 2023-07-16T00:33:47.677+0800: 7.619: [Full GC (Allocation Failure) 2023-07-16T00:33:47.677+0800: 7.619: [CMS: 34135K->34135K(34176K), 0.0011118 secs] 49344K->49344K(49536K), [Metaspace: 3817K->3817K(1056768K)], 0.0011280 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  57. 2023-07-16T00:33:47.678+0800: 7.620: [GC (CMS Initial Mark) [1 CMS-initial-mark: 34135K(34176K)] 49431K(49536K), 0.0002294 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  58. 2023-07-16T00:33:47.679+0800: 7.621: [CMS-concurrent-mark-start]
  59. 2023-07-16T00:33:47.679+0800: 7.621: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  60. 2023-07-16T00:33:47.679+0800: 7.621: [CMS-concurrent-preclean-start]
  61. 2023-07-16T00:33:47.679+0800: 7.622: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  62. 2023-07-16T00:33:47.679+0800: 7.622: [CMS-concurrent-abortable-preclean-start]
  63. 2023-07-16T00:33:47.679+0800: 7.622: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  64. 2023-07-16T00:33:47.680+0800: 7.622: [GC (CMS Final Remark) [YG occupancy: 15299 K (15360 K)]2023-07-16T00:33:47.680+0800: 7.622: [Rescan (parallel) , 0.0002939 secs]2023-07-16T00:33:47.680+0800: 7.622: [weak refs processing, 0.0000048 secs]2023-07-16T00:33:47.680+0800: 7.622: [class unloading, 0.0000805 secs]2023-07-16T00:33:47.680+0800: 7.622: [scrub symbol table, 0.0001498 secs]2023-07-16T00:33:47.680+0800: 7.622: [scrub string table, 0.0000594 secs][1 CMS-remark: 34135K(34176K)] 49435K(49536K), 0.0006129 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
  65. 2023-07-16T00:33:47.680+0800: 7.622: [CMS-concurrent-sweep-start]
  66. Heap
  67.  par new generation   total 15360K, used 15300K [0x00000000fce00000, 0x00000000fdea0000, 0x00000000fdea0000)
  68.   eden space 13696K, 100% used [0x00000000fce00000, 0x00000000fdb60000, 0x00000000fdb60000)
  69.   from space 1664K,  96% used [0x00000000fdb60000, 0x00000000fdcf1280, 0x00000000fdd00000)
  70.   to   space 1664K,   0% used [0x00000000fdd00000, 0x00000000fdd00000, 0x00000000fdea0000)
  71.  concurrent mark-sweep generation total 34176K, used 34135K [0x00000000fdea0000, 0x0000000100000000, 0x0000000100000000)
  72.  Metaspace       used 3851K, capacity 4536K, committed 4864K, reserved 1056768K
  73.   class space    used 424K, capacity 428K, committed 512K, reserved 1048576K

G1

  1. -Xloggc:d:/gc-g1-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps  
  2. -XX:+PrintGCTimeStamps -XX:+PrintGCCause  -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -XX:+UseG1GC

GC日志分析工具

上面的这些参数，能够帮我们查看分析GC的垃圾收集情况。但是如果GC日志很多很多，成千上万行。就算你一目十行，看完了，脑子也是一片空白。所以我们可以借助一些功能来帮助我们分析，这里推荐一个gceasy(https://gceasy.io)，可以上传gc文件，然后他会利用可视化的界面来展现GC情况。具体下图所示

从上图可以看到年轻代，老年代，以及永久代的内存分配，和最大使用情况。

从上图可以看到堆内存在GC之前和之后的变化，以及其他信息。

这个工具还提供基于机器学习的JVM智能优化建议，当然现在这个功能需要付费

三、JVM参数汇总查看命令

  1. java -XX:+PrintFlagsInitial 表示打印出所有参数选项的默认值
  2.  
  3. java -XX:+PrintFlagsFinal 表示打印出所有参数选项在运行程序时生效的值

四、Class常量池与运行时常量池

Class常量池可以理解为是Class文件中的资源仓库。 Class文件中除了包含类的版本、字段、方法、接口等描述信息外，还有一项信息就是常量池(constant pool table)，用于存放编译期生成的各种字面量(Literal)和符号引用(Symbolic References)。

一个class文件的16进制大体结构如下图：

对应的含义如下，细节可以查下oracle官方文档

当然一般不会去人工解析这种16进制的字节码文件，我们一般可以通过javap命令生成更可读的JVM字节码指令文件：

javap -v Math.class

红框Constant pool标出的就是class常量池信息，常量池中主要存放两大类常量：字面量和符号引用。

字面量

字面量就是指由字母、数字等构成的字符串或者数值常量

字面量只可以右值出现，所谓右值是指等号右边的值，如：int a=1 这里的a为左值，1为右值。在这个例子中1就是字面量。

  1. int a = 1;
  2. int b = 2;
  3. int c = "abcdefg";
  4. int d = "abcdefg";

符号引用

符号引用是编译原理中的概念，是相对于直接引用来说的。主要包括了以下三类常量：

  • 类和接口的全限定名 
  • 字段的名称和描述符 
  • 方法的名称和描述符

上面的a，b就是字段名称，就是一种符号引用，还有Math类常量池里的 Lcom/study/jvm/Math 是类的全限定名，main和compute是方法名称，()是一种UTF8格式的描述符，这些都是符号引用。

这些常量池现在是静态信息，只有到运行时被加载到内存后，这些符号才有对应的内存地址信息，这些常量池一旦被装入内存就变成运行时常量池，对应的符号引用在程序加载或运行时会被转变为被加载到内存区域的代码的直接引用，也就是我们说的动态链接了。例如，compute()这个符号引用在运行时就会被转变为compute()方法具体代码在内存中的地址，主要通过对象头里的类型指针去转换直接引用。

五、字符串常量池

字符串常量池的设计思想

1.字符串的分配，和其他的对象分配一样，耗费高昂的时间与空间代价，作为最基础的数据类型，大量频繁的创建字符串，极大程度地影响程序的性能

2.JVM为了提高性能和减少内存开销，在实例化字符串常量的时候进行了一些优化

  • 为字符串开辟一个字符串常量池，类似于缓存区
  • 创建字符串常量时，首先查询字符串常量池是否存在该字符串
  • 存在该字符串，返回引用实例，不存在，实例化该字符串并放入池中

三种字符串操作(jdk1.7 及以上版本)

  • 直接赋值字符串
String s = "bubble";  // s指向常量池中的引用

这种方式创建的字符串对象，只会在常量池中。

因为有"bubble"这个字面量，创建对象s的时候，JVM会先去常量池中通过 equals(key) 方法，判断是否有相同的对象

如果有，则直接返回该对象在常量池中的引用；

如果没有，则会在常量池中创建一个新对象，再返回引用。

  • new String();
String s1 = new String("bubble");  // s1指向内存中的对象引用

这种方式会保证字符串常量池和堆中都有这个对象，没有就创建，最后返回堆内存中的对象引用。

步骤大致如下：

因为有"bubble"这个字面量，所以会先检查字符串常量池中是否存在字符串"bubble"

不存在，先在字符串常量池里创建一个字符串对象；再去内存中创建一个字符串对象"bubble"；

存在的话，就直接去堆内存中创建一个字符串对象"bubble"；

最后，将内存中的引用返回。

  • intern方法
  1. String s1 = new String("bubble");   
  2. String s2 = s1.intern();
  3.  
  4. System.out.println(s1 == s2);  //false

String中的intern方法是一个 native 的方法，当调用 intern方法时，如果池已经包含一个等于此String对象的字符串（用equals(oject)方法确定），则返回池中的字符串。否则，将intern返回的引用指向当前字符串 s1(jdk1.6版本需要将 s1 复制到字符串常量池里)。

字符串常量池位置

jdk1.6及之前： 有永久代, 运行时常量池在永久代，运行时常量池包含字符串常量池

jdk1.7：有永久代，但已经逐步“去永久代”，字符串常量池从永久代里的运行时常量池分离到堆里

jdk1.8及之后： 无永久代，运行时常量池在元空间，字符串常量池里依然在堆里

用一个程序证明下字符串常量池在哪里：

  1. /**
  2.  * jdk6：-Xms6M -Xmx6M -XX:PermSize=6M -XX:MaxPermSize=6M  
  3.  * jdk8：-Xms6M -Xmx6M -XX:MetaspaceSize=6M -XX:MaxMetaspaceSize=6M
  4.  */
  5. public class RuntimeConstantPoolOOM{
  6.     public static void main(String[] args) {
  7.         ArrayList<String> list = new ArrayList<String>();
  8.         for (int i = 0; i < 10000000; i++) {
  9.             String str = String.valueOf(i).intern();
  10.             list.add(str);
  11.         }
  12.     }
  13. }
  14.  
  15. 运行结果：
  16. jdk7及以上：Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
  17. jdk6：Exception in thread "main" java.lang.OutOfMemoryError: PermGen space

字符串常量池设计原理

字符串常量池底层是hotspot的C++实现的，底层类似一个 HashTable， 保存的本质上是字符串对象的引用。

看一道比较常见的面试题，下面的代码创建了多少个 String 对象？

  1. String s1 = new String("he") + new String("llo");
  2. String s2 = s1.intern();
  3.  
  4. System.out.println(s1 == s2);
  5. // 在 JDK 1.6 下输出是 false，创建了 6 个对象
  6. // 在 JDK 1.7 及以上的版本输出是 true，创建了 5 个对象
  7. // 当然我们这里没有考虑GC，但这些对象确实存在或存在过

为什么输出会有这些变化呢？主要还是字符串池从永久代中脱离、移入堆区的原因， intern() 方法也相应发生了变化：

1、在 JDK 1.6 中，调用 intern() 首先会在字符串池中寻找 equal() 相等的字符串，假如字符串存在就返回该字符串在字符串池中的引用；假如字符串不存在，虚拟机会重新在永久代上创建一个实例，将 StringTable 的一个表项指向这个新创建的实例。

2、在 JDK 1.7 (及以上版本)中，由于字符串池不在永久代了，intern() 做了一些修改，更方便地利用堆中的对象。字符串存在时和 JDK 1.6一样，但是字符串不存在时不再需要重新创建实例，可以直接指向堆上的实例。

由上面两个图，也不难理解为什么 JDK 1.6 字符串池溢出会抛出 OutOfMemoryError: PermGen space ，而在 JDK 1.7 及以上版本抛出 OutOfMemoryError: Java heap space 。

String常量池问题的几个例子

示例1：

  1. String s0="bubble";
  2. String s1="bubble";
  3. String s2="bu" + "bble";
  4. System.out.println( s0==s1 ); //true
  5. System.out.println( s0==s2 ); //true

分析：因为例子中的 s0和s1中的”bubble”都是字符串常量，它们在编译期就被确定了，所以s0==s1为true；而”bu”和”bble”也都是字符串常量，当一个字符串由多个字符串常量连接而成时，它自己肯定也是字符串常量，所以s2也同样在编译期就被优化为一个字符串常量"bubble"，所以s2也是常量池中” bubble”的一个引用。所以我们得出s0==s1==s2；

示例2：

  1. tring s0="bubble";
  2. String s1=new String("bubble");
  3. String s2="bu" + new String("bble");
  4. System.out.println( s0==s1 );　　// false
  5. System.out.println( s0==s2 )；　 // false
  6. System.out.println( s1==s2 );　　// false

分析：用new String() 创建的字符串不是常量，不能在编译期就确定，所以new String() 创建的字符串不放入常量池中，它们有自己的地址空间。

s0还是常量池 中"bubble”的引用，s1因为无法在编译期确定，所以是运行时创建的新对象”bubble”的引用，s2因为有后半部分 new String(”bble”)所以也无法在编译期确定，所以也是一个新创建对象”bubble”的引用；明白了这些也就知道为何得出此结果了。

示例3：

  1. String a = "a1";
  2. String b = "a" + 1;
  3. System.out.println(a == b); // true 
  4.   
  5. String a = "atrue";
  6. String b = "a" + "true";
  7. System.out.println(a == b); // true 
  8.  
  9. String a = "a3.4";
  10. String b = "a" + 3.4;
  11. System.out.println(a == b); // true

分析：JVM对于字符串常量的"+"号连接，将在程序编译期，JVM就将常量字符串的"+"连接优化为连接后的值，拿"a" + 1来说，经编译器优化后在class中就已经是a1。在编译期其字符串常量的值就确定下来，故上面程序最终的结果都为true。

示例4：

  1. String a = "ab";
  2. String bb = "b";
  3. String b = "a" + bb;
  4.  
  5. System.out.println(a == b); // false

分析：JVM对于字符串引用，由于在字符串的"+"连接中，有字符串引用存在，而引用的值在程序编译期是无法确定的，即"a" + bb无法被编译器优化，只有在程序运行期来动态分配并将连接后的新地址赋给b。所以上面程序的结果也就为false。

示例5：

  1. String a = "ab";
  2. final String bb = "b";
  3. String b = "a" + bb;
  4.  
  5. System.out.println(a == b); // true

分析：和示例4中唯一不同的是bb字符串加了final修饰，对于final修饰的变量，它在编译时被解析为常量值的一个本地拷贝存储到自己的常量池中或嵌入到它的字节码流中。所以此时的"a" + bb和"a" + "b"效果是一样的。故上面程序的结果为true。

示例6：

  1. String a = "ab";
  2. final String bb = getBB();
  3. String b = "a" + bb;
  4.  
  5. System.out.println(a == b); // false
  6.  
  7. private static String getBB() {  
  8.     return "b";  
  9. }

分析：JVM对于字符串引用bb，它的值在编译期无法确定，只有在程序运行期调用方法后，将方法的返回值和"a"来动态连接并分配地址为b，故上面 程序的结果为false。

关于String是不可变的

通过上面例子可以得出得知：

  1. String  s  =  "a" + "b" + "c";  //就等价于String s = "abc";
  2. String  a  =  "a";
  3. String  b  =  "b";
  4. String  c  =  "c";
  5. String  s1  =   a  +  b  +  c;

s1 这个就不一样了，可以通过观察其JVM指令码发现s1的"+"操作会变成如下操作：

  1. StringBuilder temp = new StringBuilder();
  2. temp.append(a).append(b).append(c);
  3. String s = temp.toString();

最后再看一个例子：

  1. //字符串常量池："计算机"和"技术"     堆内存：str1引用的对象"计算机技术"  
  2. //堆内存中还有个StringBuilder的对象，但是会被gc回收，StringBuilder的toString方法会new String()，这个String才是真正返回的对象引用
  3. String str2 = new StringBuilder("计算机").append("技术").toString();   //没有出现"计算机技术"字面量，所以不会在常量池里生成"计算机技术"对象
  4. System.out.println(str2 == str2.intern());  //true
  5. //"计算机技术" 在池中没有，但是在heap中存在，则intern时，会直接返回该heap中的引用
  6.  
  7. //字符串常量池："ja"和"va"     堆内存：str1引用的对象"java"  
  8. //堆内存中还有个StringBuilder的对象，但是会被gc回收，StringBuilder的toString方法会new String()，这个String才是真正返回的对象引用
  9. String str1 = new StringBuilder("ja").append("va").toString();    //没有出现"java"字面量，所以不会在常量池里生成"java"对象
  10. System.out.println(str1 == str1.intern());  //false
  11. //java是关键字，在JVM初始化的相关类里肯定早就放进字符串常量池了
  12.  
  13. String s1=new String("test");  
  14. System.out.println(s1==s1.intern());   //false
  15. //"test"作为字面量，放入了池中，而new时s1指向的是heap中新生成的string对象，s1.intern()指向的是"test"字面量之前在池中生成的字符串对象
  16.  
  17. //字符串常量池："abc"     堆内存：s2引用的对象"abc"  
  18. //堆内存中还有个StringBuilder的对象，但是会被gc回收，StringBuilder的toString方法会new String()，这个String才是真正返回的对象引用
  19. String s2=new StringBuilder("abc").toString();
  20. System.out.println(s2==s2.intern());  //false
  21. //"abc"在常量池有,在heap中也存在，则intern时，会返回常量池中的引用

六、八种基本类型的包装类和对象池

java中基本类型的包装类的大部分都实现了常量池技术(严格来说应该叫对象池，在堆上)，这些类是Byte，Short，Integer，Long，Character，Boolean，另外两种浮点数类型的包装类则没有实现。另外Byte，Short，Integer，Long，Character这5种整型的包装类也只是在对应值小于等于127时才可使用对象池，也即对象不负责创建和管理大于127的这些类的对象。因为一般这种比较小的数用到的概率相对较大。

  1. public class Test {
  2.  
  3.     public static void main(String[] args) {
  4.         //5种整形的包装类Byte,Short,Integer,Long,Character的对象，  
  5.         //在值小于127时可以使用对象池  
  6.         Integer i1 = 127;  //这种调用底层实际是执行的Integer.valueOf(127)，里面用到了IntegerCache对象池
  7.         Integer i2 = 127;
  8.         System.out.println(i1 == i2);//输出true  
  9.  
  10.         //值大于127时，不会从对象池中取对象  
  11.         Integer i3 = 128;
  12.         Integer i4 = 128;
  13.         System.out.println(i3 == i4);//输出false  
  14.         
  15.         //用new关键词新生成对象不会使用对象池
  16.         Integer i5 = new Integer(127);  
  17.         Integer i6 = new Integer(127);
  18.         System.out.println(i5 == i6);//输出false 
  19.  
  20.         //Boolean类也实现了对象池技术  
  21.         Boolean bool1 = true;
  22.         Boolean bool2 = true;
  23.         System.out.println(bool1 == bool2);//输出true  
  24.  
  25.         //浮点类型的包装类没有实现对象池技术  
  26.         Double d1 = 1.0;
  27.         Double d2 = 1.0;
  28.         System.out.println(d1 == d2);//输出false  
  29.     }
  30. }

声明：本文内容由网友自发贡献，不代表【wpsshop博客】立场，版权归原作者所有，本站不承担相应法律责任。如您发现有侵权的内容，请联系我们。转载请注明出处：https://www.wpsshop.cn/w/我家自动化/article/detail/995007
推荐阅读
相关标签

Copyright © 2003-2013 www.wpsshop.cn 版权所有，并保留所有权利。

  

闽ICP备14008679号