目錄
一、阿里巴巴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 之后自行探索。
- 是否有一個全局視角來查看系統的運行狀況?
- 為什么 CPU 又升高了,到底是哪里占用了 CPU ?
- 運行的多線程有死鎖嗎?有阻塞嗎?
- 程序運行耗時很長,是哪里耗時比較長呢?如何監測呢?
- 這個類從哪個 jar 包加載的?為什么會報各種類相關的 Exception?
- 我改的代碼為什么沒有執行到?難道是我沒 commit?分支搞錯了?
- 遇到問題無法在線上 debug,難道只能通過加日志再重新發布嗎?
- 有什么辦法可以監控到 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使用
# github下載arthas
wget https://alibaba.github.io/arthas/arthas-boot.jar
# 或者 Gitee 下載
wget https://arthas.gitee.io/arthas-boot.jar
用java -jar運行即可,可以識別機器上所有Java進程(我們這里之前已經運行了一個Arthas測試程序,代碼見下方)
package com.study.jvm;import java.util.HashSet;public class Arthas {private static HashSet hashSet = new HashSet();public static void main(String[] args) {// 模擬 CPU 過高cpuHigh();// 模擬線程死鎖deadThread();// 不斷的向 hashSet 集合增加數據addHashSetThread();}/*** 不斷的向 hashSet 集合添加數據*/public static void addHashSetThread() {// 初始化常量new Thread(() -> {int count = 0;while (true) {try {hashSet.add("count" + count);Thread.sleep(1000);count++;} catch (InterruptedException e) {e.printStackTrace();}}}).start();}public static void cpuHigh() {new Thread(() -> {while (true) {}}).start();}/*** 死鎖*/private static void deadThread() {/** 創建資源 */Object resourceA = new Object();Object resourceB = new Object();// 創建線程Thread threadA = new Thread(() -> {synchronized (resourceA) {System.out.println(Thread.currentThread() + " get ResourceA");try {Thread.sleep(1000);} catch (InterruptedException e) {e.printStackTrace();}System.out.println(Thread.currentThread() + "waiting get resourceB");synchronized (resourceB) {System.out.println(Thread.currentThread() + " get resourceB");}}});Thread threadB = new Thread(() -> {synchronized (resourceB) {System.out.println(Thread.currentThread() + " get ResourceB");try {Thread.sleep(1000);} catch (InterruptedException e) {e.printStackTrace();}System.out.println(Thread.currentThread() + "waiting get resourceA");synchronized (resourceA) {System.out.println(Thread.currentThread() + " get resourceA");}}});threadA.start();threadB.start();}
}
選擇進程序號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,寫滿了會循環覆蓋
-Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M
Tomcat則直接加在JAVA_OPTS變量里。
如何分析GC日志
運行程序加上對應gc日志
java -jar -Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause
-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都是由于元空間不夠導致的,所以我們可以將元空間調大點
java -jar -Xloggc:./gc-adjust-%t.log -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M microservice-eureka-server.jar
調整完我們再看下gc日志發現已經沒有因為元空間不夠導致的fullgc了
對于CMS和G1收集器的日志會有一點不一樣,也可以試著打印下對應的gc日志分析下,可以發現gc日志里面的gc步驟跟我們之前講過的步驟是類似的
public class HeapTest {byte[] a = new byte[1024 * 100]; //100KBpublic static void main(String[] args) throws InterruptedException {ArrayList<HeapTest> heapTests = new ArrayList<>();while (true) {heapTests.add(new HeapTest());Thread.sleep(10);}}
}
CMS
-Xloggc:d:/gc-cms-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps -XX:+PrintGCCause -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC
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)
Memory: 4k page, physical 66891640k(45889116k free), swap 71085944k(46785224k free)
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
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]
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]
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]
2023-07-16T00:33:43.748+0800: 3.691: [CMS-concurrent-mark-start]
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]
2023-07-16T00:33:43.749+0800: 3.691: [CMS-concurrent-preclean-start]
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]
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]
2023-07-16T00:33:43.750+0800: 3.692: [CMS-concurrent-sweep-start]
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]
2023-07-16T00:33:43.750+0800: 3.693: [CMS-concurrent-reset-start]
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]
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]
2023-07-16T00:33:45.756+0800: 5.698: [CMS-concurrent-mark-start]
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]
2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-preclean-start]
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]
2023-07-16T00:33:45.757+0800: 5.699: [CMS-concurrent-abortable-preclean-start]
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]
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]
2023-07-16T00:33:45.758+0800: 5.700: [CMS-concurrent-sweep-start]
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]
2023-07-16T00:33:45.758+0800: 5.701: [CMS-concurrent-reset-start]
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]
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]
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]
2023-07-16T00:33:45.814+0800: 5.756: [CMS-concurrent-mark-start]
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]
2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-preclean-start]
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]
2023-07-16T00:33:45.814+0800: 5.757: [CMS-concurrent-abortable-preclean-start]
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]
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]
2023-07-16T00:33:45.815+0800: 5.758: [CMS-concurrent-sweep-start]
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]
2023-07-16T00:33:45.816+0800: 5.758: [CMS-concurrent-reset-start]
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]
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]
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]
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]
2023-07-16T00:33:47.653+0800: 7.595: [CMS-concurrent-mark-start]
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]
2023-07-16T00:33:47.653+0800: 7.595: [CMS-concurrent-preclean-start]
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]
2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-abortable-preclean-start]
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]
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]
2023-07-16T00:33:47.654+0800: 7.596: [CMS-concurrent-sweep-start]
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]
2023-07-16T00:33:47.655+0800: 7.597: [CMS-concurrent-reset-start]
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]
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]
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]
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]
2023-07-16T00:33:47.679+0800: 7.621: [CMS-concurrent-mark-start]
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]
2023-07-16T00:33:47.679+0800: 7.621: [CMS-concurrent-preclean-start]
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]
2023-07-16T00:33:47.679+0800: 7.622: [CMS-concurrent-abortable-preclean-start]
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]
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]
2023-07-16T00:33:47.680+0800: 7.622: [CMS-concurrent-sweep-start]
Heappar new generation total 15360K, used 15300K [0x00000000fce00000, 0x00000000fdea0000, 0x00000000fdea0000)eden space 13696K, 100% used [0x00000000fce00000, 0x00000000fdb60000, 0x00000000fdb60000)from space 1664K, 96% used [0x00000000fdb60000, 0x00000000fdcf1280, 0x00000000fdd00000)to space 1664K, 0% used [0x00000000fdd00000, 0x00000000fdd00000, 0x00000000fdea0000)concurrent mark-sweep generation total 34176K, used 34135K [0x00000000fdea0000, 0x0000000100000000, 0x0000000100000000)Metaspace used 3851K, capacity 4536K, committed 4864K, reserved 1056768Kclass space used 424K, capacity 428K, committed 512K, reserved 1048576K
G1
-Xloggc:d:/gc-g1-%t.log -Xms50M -Xmx50M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-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參數匯總查看命令
java -XX:+PrintFlagsInitial 表示打印出所有參數選項的默認值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就是字面量。
int a = 1;
int b = 2;
int c = "abcdefg";
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方法
String s1 = new String("bubble");
String s2 = s1.intern();System.out.println(s1 == s2); //false
String中的intern方法是一個 native 的方法,當調用 intern方法時,如果池已經包含一個等于此String對象的字符串(用equals(oject)方法確定),則返回池中的字符串。否則,將intern返回的引用指向當前字符串 s1(jdk1.6版本需要將 s1 復制到字符串常量池里)。
字符串常量池位置
jdk1.6及之前: 有永久代, 運行時常量池在永久代,運行時常量池包含字符串常量池
jdk1.7:有永久代,但已經逐步“去永久代”,字符串常量池從永久代里的運行時常量池分離到堆里
jdk1.8及之后: 無永久代,運行時常量池在元空間,字符串常量池里依然在堆里
用一個程序證明下字符串常量池在哪里:
/*** jdk6:-Xms6M -Xmx6M -XX:PermSize=6M -XX:MaxPermSize=6M * jdk8:-Xms6M -Xmx6M -XX:MetaspaceSize=6M -XX:MaxMetaspaceSize=6M*/
public class RuntimeConstantPoolOOM{public static void main(String[] args) {ArrayList<String> list = new ArrayList<String>();for (int i = 0; i < 10000000; i++) {String str = String.valueOf(i).intern();list.add(str);}}
}運行結果:
jdk7及以上:Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
jdk6:Exception in thread "main" java.lang.OutOfMemoryError: PermGen space
字符串常量池設計原理
字符串常量池底層是hotspot的C++實現的,底層類似一個 HashTable, 保存的本質上是字符串對象的引用。
看一道比較常見的面試題,下面的代碼創建了多少個 String 對象?
String s1 = new String("he") + new String("llo");
String s2 = s1.intern();System.out.println(s1 == s2);
// 在 JDK 1.6 下輸出是 false,創建了 6 個對象
// 在 JDK 1.7 及以上的版本輸出是 true,創建了 5 個對象
// 當然我們這里沒有考慮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:
String s0="bubble";
String s1="bubble";
String s2="bu" + "bble";
System.out.println( s0==s1 ); //true
System.out.println( s0==s2 ); //true
分析:因為例子中的 s0和s1中的”bubble”都是字符串常量,它們在編譯期就被確定了,所以s0==s1為true;而”bu”和”bble”也都是字符串常量,當一個字符串由多個字符串常量連接而成時,它自己肯定也是字符串常量,所以s2也同樣在編譯期就被優化為一個字符串常量"bubble",所以s2也是常量池中” bubble”的一個引用。所以我們得出s0==s1==s2;
示例2:
tring s0="bubble";
String s1=new String("bubble");
String s2="bu" + new String("bble");
System.out.println( s0==s1 ); // false
System.out.println( s0==s2 ); // false
System.out.println( s1==s2 ); // false
分析:用new String() 創建的字符串不是常量,不能在編譯期就確定,所以new String() 創建的字符串不放入常量池中,它們有自己的地址空間。
s0還是常量池 中"bubble”的引用,s1因為無法在編譯期確定,所以是運行時創建的新對象”bubble”的引用,s2因為有后半部分 new String(”bble”)所以也無法在編譯期確定,所以也是一個新創建對象”bubble”的引用;明白了這些也就知道為何得出此結果了。
示例3:
String a = "a1";
String b = "a" + 1;
System.out.println(a == b); // true String a = "atrue";
String b = "a" + "true";
System.out.println(a == b); // true String a = "a3.4";
String b = "a" + 3.4;
System.out.println(a == b); // true
分析:JVM對于字符串常量的"+"號連接,將在程序編譯期,JVM就將常量字符串的"+"連接優化為連接后的值,拿"a" + 1來說,經編譯器優化后在class中就已經是a1。在編譯期其字符串常量的值就確定下來,故上面程序最終的結果都為true。
示例4:
String a = "ab";
String bb = "b";
String b = "a" + bb;System.out.println(a == b); // false
分析:JVM對于字符串引用,由于在字符串的"+"連接中,有字符串引用存在,而引用的值在程序編譯期是無法確定的,即"a" + bb無法被編譯器優化,只有在程序運行期來動態分配并將連接后的新地址賦給b。所以上面程序的結果也就為false。
示例5:
String a = "ab";
final String bb = "b";
String b = "a" + bb;System.out.println(a == b); // true
分析:和示例4中唯一不同的是bb字符串加了final修飾,對于final修飾的變量,它在編譯時被解析為常量值的一個本地拷貝存儲到自己的常量池中或嵌入到它的字節碼流中。所以此時的"a" + bb和"a" + "b"效果是一樣的。故上面程序的結果為true。
示例6:
String a = "ab";
final String bb = getBB();
String b = "a" + bb;System.out.println(a == b); // falseprivate static String getBB() { return "b";
}
分析:JVM對于字符串引用bb,它的值在編譯期無法確定,只有在程序運行期調用方法后,將方法的返回值和"a"來動態連接并分配地址為b,故上面 程序的結果為false。
關于String是不可變的
通過上面例子可以得出得知:
String s = "a" + "b" + "c"; //就等價于String s = "abc";
String a = "a";
String b = "b";
String c = "c";
String s1 = a + b + c;
s1 這個就不一樣了,可以通過觀察其JVM指令碼發現s1的"+"操作會變成如下操作:
StringBuilder temp = new StringBuilder();
temp.append(a).append(b).append(c);
String s = temp.toString();
最后再看一個例子:
//字符串常量池:"計算機"和"技術" 堆內存:str1引用的對象"計算機技術"
//堆內存中還有個StringBuilder的對象,但是會被gc回收,StringBuilder的toString方法會new String(),這個String才是真正返回的對象引用
String str2 = new StringBuilder("計算機").append("技術").toString(); //沒有出現"計算機技術"字面量,所以不會在常量池里生成"計算機技術"對象
System.out.println(str2 == str2.intern()); //true
//"計算機技術" 在池中沒有,但是在heap中存在,則intern時,會直接返回該heap中的引用//字符串常量池:"ja"和"va" 堆內存:str1引用的對象"java"
//堆內存中還有個StringBuilder的對象,但是會被gc回收,StringBuilder的toString方法會new String(),這個String才是真正返回的對象引用
String str1 = new StringBuilder("ja").append("va").toString(); //沒有出現"java"字面量,所以不會在常量池里生成"java"對象
System.out.println(str1 == str1.intern()); //false
//java是關鍵字,在JVM初始化的相關類里肯定早就放進字符串常量池了String s1=new String("test");
System.out.println(s1==s1.intern()); //false
//"test"作為字面量,放入了池中,而new時s1指向的是heap中新生成的string對象,s1.intern()指向的是"test"字面量之前在池中生成的字符串對象//字符串常量池:"abc" 堆內存:s2引用的對象"abc"
//堆內存中還有個StringBuilder的對象,但是會被gc回收,StringBuilder的toString方法會new String(),這個String才是真正返回的對象引用
String s2=new StringBuilder("abc").toString();
System.out.println(s2==s2.intern()); //false
//"abc"在常量池有,在heap中也存在,則intern時,會返回常量池中的引用
六、八種基本類型的包裝類和對象池
java中基本類型的包裝類的大部分都實現了常量池技術(嚴格來說應該叫對象池,在堆上),這些類是Byte,Short,Integer,Long,Character,Boolean,另外兩種浮點數類型的包裝類則沒有實現。另外Byte,Short,Integer,Long,Character這5種整型的包裝類也只是在對應值小于等于127時才可使用對象池,也即對象不負責創建和管理大于127的這些類的對象。因為一般這種比較小的數用到的概率相對較大。
public class Test {public static void main(String[] args) {//5種整形的包裝類Byte,Short,Integer,Long,Character的對象, //在值小于127時可以使用對象池 Integer i1 = 127; //這種調用底層實際是執行的Integer.valueOf(127),里面用到了IntegerCache對象池Integer i2 = 127;System.out.println(i1 == i2);//輸出true //值大于127時,不會從對象池中取對象 Integer i3 = 128;Integer i4 = 128;System.out.println(i3 == i4);//輸出false //用new關鍵詞新生成對象不會使用對象池Integer i5 = new Integer(127); Integer i6 = new Integer(127);System.out.println(i5 == i6);//輸出false //Boolean類也實現了對象池技術 Boolean bool1 = true;Boolean bool2 = true;System.out.println(bool1 == bool2);//輸出true //浮點類型的包裝類沒有實現對象池技術 Double d1 = 1.0;Double d2 = 1.0;System.out.println(d1 == d2);//輸出false }
}