OpenJDK 11 JVM日誌相關參數解析與使用
OpenJDK 11 是在 OpenJDK 8 以後的第一個長期支持版本，這一版本在JVM日誌配置有了很大改動，主要是規範化，統一化了。在 OpenJDK 8 中，日誌配置有不少狀態位，讓人摸不着頭腦，而且比較難以維護與進一步迭代。在 OpenJDK 11終於將JVM日誌相關的配置規範起來，統一配置。這篇文章會對於這些配置作一個基本的說明和解析。java
1、JVM日誌標籤
JVM 日誌和咱們 java 代碼中的日誌，實際上是相似。在 Java 代碼中，咱們通常使用 slf4j 記錄日誌，例如：算法
Logger logger = LogFactory.getLooger("core-logger");
logger.info("this is core logger log");
而後日誌中就會輸出相似於：app
2020-02-05 10:50:52.670 INFO [core-logger] [22] [pool-13-thread-1]: this is core logger log
包括時間戳，日誌級別，日誌標籤（core-logger），日誌內容這些信息。JVM 日誌也是包括這些元素。舉個例子：maven
[0.182s][debug][jit,compilation] 1 3 java.lang.StringLatin1::hashCode (42 bytes) [0.183s][debug][jit,compilation] 2 3 java.lang.Object::<init> (1 bytes) [0.183s][debug][jit,compilation] 3 3 java.lang.String::hashCode (49 bytes)
能夠看出，默認的 JVM 日誌包括：學習
[啓動通過時間][日誌級別][日誌標籤，可能包含多個] 日誌內容
其中一行日誌，可能包含多個標籤，以後關於JVM日誌相關的配置，也是圍繞着這些標籤進行配置。大部分的標籤是給JVM開發者用的，其中某些標籤供咱們使用 JVM 的人進行 JVM 參數調優以及代碼調優。那麼咱們須要關心哪些標籤呢？我我的按照功能，把咱們須要關心的標籤分爲以下幾大類優化
1. gc相關
gc日誌有不少標籤與組合，大部分以 gc 標籤爲開始，混合搭配其餘一些標籤。通常，有以下幾個標籤咱們會常常用到：this
標籤gcspa
gc整體描述日誌，通常設置info級別查看gc的發生時間，消耗時間還有內存大小。例如：Pause Young (Normal) (g1 Evacuation Pause) 3480M->1565M(5120M) 15.968ms 包含了gc類型，gc緣由，收集內存大小，持續時間等信息.net
標籤gc,ageprototype
gc 中 age 相關信息，age比較高的對象會進入老年代。若是是 trace 級別，會輸出每個 age 的全部對象佔用總大小，以及比這個 age 低的全部 age 的大小，debug 級別只會輸出最高級別的 age 以及指望大小，不是當前總大小，例如：
[2020-02-26T08:34:12.823+0000][debug][gc,age ] gc(1661) Desired survivor size 167772160 bytes, new threshold 6 (max threshold 6) [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 1: 16125960 bytes, 16125960 total [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 2: 16259512 bytes, 32385472 total [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 3: 2435240 bytes, 34820712 total [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 4: 17179320 bytes, 52000032 total [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 5: 43986952 bytes, 95986984 total [2020-02-26T08:34:12.823+0000][trace][gc,age ] age 6: 20858328 bytes, 116845312 total
標籤gc,alloc，gc,alloc,region
這兩個參數僅對 g1 gc 有效 gc,alloc 在 gc 完成的時候，打印 trace 級別日誌記錄觸發 gc 的線程是哪個以及返回的 gc 結果地址;這個通常是在調試 gc 的時候才須要看這個日誌。 gc,alloc,region 統計每次 gc 的 Regions 信息，打印 debug 級別日誌。
[2020-02-28T02:14:02.694+0000][trace][gc,alloc ] sdk-27692-2-amqp-t-4: Successfully scheduled collection returning 0x00000007ffc00000 [2020-02-28T02:16:00.372+0000][debug][gc,alloc,region ] gc(7848) Mutator Allocation stats, regions: 677, wasted size: 63832B ( 0.0%)
標籤gc,cpu 這個是大多數 gc 問題定位須要查看的日誌， info 級別打印每次gc真正耗時：
[2020-02-28T01:59:46.406+0000][info ][gc,cpu ] gc(7841) User=0.10s Sys=0.00s Real=0.04s [2020-02-28T02:01:20.148+0000][info ][gc,cpu ] gc(7842) User=0.04s Sys=0.06s Real=0.04s
注意這個和 JFR 的統計可能會有差別，JFR 統計的 gc 時間是從開始 schedule gc 就認爲開始 gc ，而這裏的時間是從開始標記開始。
標籤gc,ergo，gc,ergo,cset，gc,ergo,ihop，gc,ergo,refine
這是 Adaptive Size Policy 相關的日誌，若是想詳細學習算法，能夠用 trace 級別，通常的 debug 級別信息就夠了
[2020-02-28T01:59:46.367+0000][trace][gc,ergo,cset ] gc(7841) Start choosing CSet. pending cards: 26996 predicted base time: 13.34ms remaining time: 186.66ms target pause time: 200.00ms [2020-02-28T01:59:46.367+0000][trace][gc,ergo,cset ] gc(7841) Add young regions to CSet. eden: 676 regions, survivors: 6 regions, predicted young region time: 19.02ms, target pause time: 200.00ms [2020-02-28T01:59:46.367+0000][debug][gc,ergo,cset ] gc(7841) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 167.64 [2020-02-28T01:59:46.389+0000][debug][gc,ergo ] gc(7841) Running g1 Clear Card Table Task using 4 workers for 7 units of work for 895 regions. [2020-02-28T01:59:46.391+0000][debug][gc,ergo ] gc(7841) Running g1 Free Collection Set using 4 workers for collection set length 682 [2020-02-28T01:59:46.391+0000][trace][gc,ergo,refine ] gc(7841) Updating Refinement Zones: update_rs time: 6.800ms, update_rs buffers: 397, update_rs goal time: 19.998ms [2020-02-28T01:59:46.391+0000][debug][gc,ergo,refine ] gc(7841) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860 [2020-02-28T02:01:20.108+0000][trace][gc,ergo,cset ] gc(7842) Start choosing CSet. pending cards: 25786 predicted base time: 12.87ms remaining time: 187.13ms target pause time: 200.00ms [2020-02-28T02:01:20.108+0000][trace][gc,ergo,cset ] gc(7842) Add young regions to CSet. eden: 677 regions, survivors: 5 regions, predicted young region time: 14.43ms, target pause time: 200.00ms [2020-02-28T02:01:20.108+0000][debug][gc,ergo,cset ] gc(7842) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 172.70 [2020-02-28T02:01:20.132+0000][debug][gc,ergo ] gc(7842) Running g1 Clear Card Table Task using 4 workers for 8 units of work for 903 regions. [2020-02-28T02:01:20.133+0000][debug][gc,ergo ] gc(7842) Running g1 Free Collection Set using 4 workers for collection set length 682 [2020-02-28T02:01:20.133+0000][trace][gc,ergo,refine ] gc(7842) Updating Refinement Zones: update_rs time: 6.303ms, update_rs buffers: 305, update_rs goal time: 19.997ms [2020-02-28T02:01:20.133+0000][debug][gc,ergo,refine ] gc(7842) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860 [2020-02-28T02:04:36.095+0000][trace][gc,ergo,cset ] gc(7843) Start choosing CSet. pending cards: 26115 predicted base time: 12.85ms remaining time: 187.15ms target pause time: 200.00ms [2020-02-28T02:04:36.095+0000][trace][gc,ergo,cset ] gc(7843) Add young regions to CSet. eden: 676 regions, survivors: 6 regions, predicted young region time: 69.11ms, target pause time: 200.00ms [2020-02-28T02:04:36.095+0000][debug][gc,ergo,cset ] gc(7843) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 118.04 [2020-02-28T02:04:36.118+0000][debug][gc,ergo ] gc(7843) Running g1 Clear Card Table Task using 4 workers for 7 units of work for 894 regions. [2020-02-28T02:04:36.120+0000][debug][gc,ergo ] gc(7843) Running g1 Free Collection Set using 4 workers for collection set length 682 [2020-02-28T02:04:36.121+0000][trace][gc,ergo,refine ] gc(7843) Updating Refinement Zones: update_rs time: 6.929ms, update_rs buffers: 364, update_rs goal time: 19.997ms [2020-02-28T02:04:36.121+0000][debug][gc,ergo,refine ] gc(7843) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860
標籤gc,heap，gc,heap,region
gc,heap的 debug 級別會顯示 gc 的時候堆的概況，對於 g1 gc gc,heap,region的 trace 級別，會打印每個 region 的詳細狀況，這個通常供 gc 調試使用。
咱們通常只須要關心gc,heap的日誌就好了
這些標籤是在
[2020-02-28T06:01:20.787+0000][debug][gc,heap ] gc(7922) Heap before gc invocations=7922 (full 0): garbage-first heap total 8388608K, used 4076387K [0x0000000600000000, 0x0000000800000000) [2020-02-28T06:01:20.787+0000][debug][gc,heap ] gc(7922) region size 4096K, 682 young (2793472K), 5 survivors (20480K) [2020-02-28T06:01:20.787+0000][debug][gc,heap ] gc(7922) Metaspace used 163068K, capacity 166731K, committed 169728K, reserved 1198080K[2020-02-28T06:01:20.787+0000][debug][gc,heap ] gc(7922) class space used 18180K, capacity 19580K, committed 20480K, reserved 1048576K [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) Heap Regions: E=young(eden), S=young(survivor), O=old, HS=humongous(starts), HC=humongous(continues), CS=collection set, F=free, A=archive, TAMS=top-at-mark-start (previous, next)[2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 0|0x0000000600000000, 0x0000000600400000, 0x0000000600400000|100%| O| |TAMS 0x0000000600400000, 0x0000000600000000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 1|0x0000000600400000, 0x0000000600800000, 0x0000000600800000|100%| O| |TAMS 0x0000000600800000, 0x0000000600400000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 2|0x0000000600800000, 0x0000000600c00000, 0x0000000600c00000|100%| O| |TAMS 0x0000000600c00000, 0x0000000600800000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 3|0x0000000600c00000, 0x0000000601000000, 0x0000000601000000|100%| O| |TAMS 0x0000000601000000, 0x0000000600c00000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 4|0x0000000601000000, 0x0000000601400000, 0x0000000601400000|100%| O| |TAMS 0x0000000601400000, 0x0000000601000000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 5|0x0000000601400000, 0x0000000601800000, 0x0000000601800000|100%| O| |TAMS 0x0000000601800000, 0x0000000601400000| Untracked [2020-02-28T06:01:20.787+0000][trace][gc,heap,region ] gc(7922) | 6|0x0000000601800000, 0x0000000601c00000, 0x0000000601c00000|100%| O| |TAMS 0x0000000601c00000, 0x0000000601800000| Untracked
標籤gc,humongous 若是你使用的是g1 gc，而且常常出現 Evacuation Failure 或者 Humongous Allocation ，而且不知道是什麼緣由的話，能夠考慮看看這個標籤相關的日誌：
[2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 219 object size 2160888 start 0x0000000636c00000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 412 object size 2160888 start 0x0000000667000000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 443 object size 3241320 start 0x000000066ec00000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 489 object size 2160888 start 0x000000067a400000 with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 490 object size 2160888 start 0x000000067a800000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 499 object size 7292936 start 0x000000067cc00000 with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 536 object size 2160888 start 0x0000000686000000 with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 656 object size 2160888 start 0x00000006a4000000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 768 object size 2160888 start 0x00000006c0000000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0 [2020-02-28T06:01:20.831+0000][debug][gc,humongous ] gc(7922) Live humongous region 786 object size 2160888 start 0x00000006c4800000 with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
標籤gc,metaspace，gc,metaspace,freelist，gc,metaspace,freelist,blocks 查看 metaspace 相關的 gc 日誌，gc,metaspace的 info 級別會輸出每次 gc 涉及的 metaspace 內存變化，若是有變化，詳細變化會經過gc,metaspace,freelist，gc,metaspace,freelist,blocks的 trace 級別輸出。
[2020-02-28T04:32:13.123+0000][info ][gc,metaspace ] gc(7896) Metaspace: 163062K->163062K(1198080K) [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] SpaceManager::grow_and_allocate for 49 words 109 words used 19 words left [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] ChunkManager::free_chunks_get: free_list: 0x00007fddccb89770 chunks left: 433. [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] ChunkManager::chunk_freelist_allocate: 0x00007fddccb89770 chunk 0x00007fdc74221000 size 128 count 433 Free chunk total 255616 count 824 [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist,blocks] returning block at 0x00007fdd95575b68 size = 19 [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] SpaceManager::added chunk: [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] Metachunk: bottom 0x00007fdc74221000 top 0x00007fdc74221040 end 0x00007fdc74221400 size 128 (specialized) [2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist ] Free chunk total 255616 count 824 [2020-02-28T04:36:35.367+0000][info ][gc,metaspace ] gc(7897) Metaspace: 163065K->163065K(1198080K)
標籤gc,phases，gc,phases,ref，gc,phases,task，gc,ref，gc,start,gc,ref,start 這些標籤與 gc 步驟相關，若是想學習 gc 算法，能夠查看這些標籤的日誌，來了解 gc 的步驟以及原理
標籤safepoint
咱們知道只有到達 safepoint，咱們才能夠進行 gc，若是咱們對這些 safepoint 感興趣，能夠查看這個標籤的 debug 級別的日誌
2. 類加載與運行時編譯相關
標籤class,preorder，class,init，class,load, class,unload 顧名思義，這是類初始化，類加載與類卸載的日誌，info 級別的信息就以足夠。 若是你想學習 JVM 類加載過程，能夠查看 class 標籤的 trace 級別日誌。
[8.931s][debug][class,preorder ] com.fasterxml.jackson.core.PrettyPrinter source: file:/D:/Repositories/maven/com/fasterxml/jackson/core/jackson-core/2.10.0/jackson-core-2.10.0.jar [8.931s][info][class,init ] 2740 Initializing 'com/fasterxml/jackson/core/PrettyPrinter' (0x0000000801399220) [8.934s][info][class,load ] com.fasterxml.jackson.core.PrettyPrinter source: file:/D:/Repositories/maven/com/fasterxml/jackson/core/jackson-core/2.10.0/jackson-core-2.10.0.jar
標籤jit,compilation 通常咱們對於即時編譯優化，只用看 jit 編譯日誌便可，對應的標籤是jit,compilation，日誌級別是 debug
[2020-02-28T03:01:51.619+0000][debug][jit,compilation] 153756 ! 4 jdk.internal.reflect.GeneratedConstructorAccessor161::newInstance (49 bytes) made zombie [2020-02-28T03:01:51.620+0000][debug][jit,compilation] 153219 4 io.lettuce.core.protocol.CommandArgs$IntegerArgument::encode (12 bytes) made zombie [2020-02-28T03:01:51.623+0000][debug][jit,compilation] 153192 4 io.lettuce.core.protocol.CommandArgs$StringArgument::writeString (60 bytes) made zombie [2020-02-28T03:01:54.911+0000][debug][jit,compilation] 157252 ! 4 jdk.internal.reflect.GeneratedConstructorAccessor161::newInstance (49 bytes)
3. 其餘運行時相關
標籤monitorinflation 同步鎖相關日誌, 通常查看 debug 級別的，能夠用於定位死鎖
[5.033s][debug][monitorinflation] Deflating object 0x0000000708310378 , mark 0x0000021cef446002 , type java.lang.ref.ReferenceQueue$Lock [5.033s][debug][monitorinflation] Inflating object 0x0000000708310378 , mark 0x0000021cf085c002 , type java.lang.ref.ReferenceQueue$Lock [5.035s][debug][monitorinflation] Deflating object 0x0000000708310378 , mark 0x0000021cf085c002 , type java.lang.ref.ReferenceQueue$Lock [5.035s][debug][monitorinflation] Inflating object 0x0000000708310378 , mark 0x0000021cef445e02 , type java.lang.ref.ReferenceQueue$Lock
標籤biasedlocking 偏向鎖相關日誌，通常查看 info 級別便可，trace 級別顯示更詳細的偏向鎖爭用細節，能夠用於學習偏向鎖實現原理
[7.273s][info ][biasedlocking] Revoking bias by walking my own stack: [7.273s][info ][biasedlocking] Revoking bias of object 0x0000000711b1ca40, mark 0x000001c6d0acc905, type sun.net.www.protocol.jar.URLJarFile, prototype header 0x0000000000000105, allow rebias 0, requesting thread 0x000001c6d0acc800 [7.273s][info ][biasedlocking] Revoked bias of object biased toward live thread (0x000001c6d0acc800) [7.273s][trace][biasedlocking] mon_info->owner (0x00000007022634d8) != obj (0x0000000711b1ca40) [7.273s][trace][biasedlocking] mon_info->owner (0x0000000711b200d8) != obj (0x0000000711b1ca40) [7.273s][trace][biasedlocking] mon_info->owner (0x0000000711b200d8) != obj (0x0000000711b1ca40) [7.273s][trace][biasedlocking] mon_info->owner (0x0000000702970260) != obj (0x0000000711b1ca40) [7.273s][info ][biasedlocking] Revoked bias of currently-unlocked object
2、JVM日誌配置
配置格式：
-Xlog[:[what][:[output][:[decorators][:output-options[,...]]]]]
若是不配置，默認的是：
-Xlog:all=warning:stdout:uptime,level,tags
這是一個冒號分割的配置，第一個冒號後面的就是what，第二個是output，第三個是decorators，第四個是逗號分割的output-options.沒有配置的部分就是上面默認值的對應部分，例以下面的幾組配置就是等價的：
-Xlog:all=warning與-Xlog::stdout與-Xlog::::uptime,level,tags與-Xlog:all=warning:stdout與-Xlog::stdout:uptime,level,tags與-Xlog:all=warning:stdout:uptime,level,tags-Xlog:gc*=info與-Xlog:gc*=info:stdout:uptime,level,tags-Xlog::file=/project/log/app.log::filecount=50,filesize=100M與-Xlog:all=warning:file=/project/log/app.log:uptime,level,tags:filecount=50,filesize=100M
1. what
what包含標籤還有日誌級別，例如你能夠配置：
-Xlog:gc=info，表示僅包含 gc 一個標籤的全部日誌，info 級別的都會輸出。-Xlog:gc*=info，表示包含 gc 標籤的全部日誌，info 級別的都會輸出，就是上面說的 gc 相關的全部標籤。-Xlog:gc+age=debug，表示同時包含且僅包含 gc 和 age 這兩個標籤的，debug 級別的纔會輸出。-Xlog:gc*=info,gc+heap=debug,gc+heap+region=debug，同時設置包含且僅包含 gc 和 heap 這兩個標籤的爲 debug，包含且僅包含 gc 和 heap 和 region 這三個標籤的設置爲 debug ，剩下的包含 gc 標籤的日誌級別爲 info 並且因爲咱們知道age標籤只和gc標籤搭配，因此還能夠這麼寫：-Xlog:gc*=info,age*=debug和-Xlog:gc*=info,gc+age=debug是等價的 對於這種能夠合併的標籤，能夠參考後面的動態修改JVM日誌級別章節來經過修改日誌參數看JVM是如何合併的。
日誌級別包括：
- off：關閉
- trace：包含trace，debug，info，warning，error全部日誌
- debug：包含debug，info，warning，error
- info：包含info，warning，error
- warning：包含warning，error
- error：僅包含error
**若是沒給出級別，那麼默認就是配置了info級別。**例如-Xlog:gc*和-Xlog:gc*=info是等價的
標籤若是打錯了，就會報錯並退出：
[0.005s][error][logging] Invalid tag 'phase' in log selection. Did you mean 'phases'? Invalid -Xlog option '-Xlog:gc+phase=debug', see error log for details.
若是沒有這種標籤的組合（或者這個標籤不能單獨出現），則會報警，可是繼續運行：
[0.006s][warning][logging] No tag set matches selection: gc+add. Did you mean any of the following? gc* gc+metaspace* gc+ref* gc+stringtable gc+compaction [0.007s][warning][logging] No tag set matches selection: phases. Did you mean any of the following? phases* gc+phases* gc+phases+start* gc+phases+task gc+phases+ref
2. output
包含三種輸出：
-
stdout： 標準輸出
-
stderr： 標準錯誤輸出
-
file=filename 輸出到文件
對於輸出到文件能夠配置output-options：filecount=50,filesize=100M這個表示保留50個文件，每一個文件100M
3. decorators
可使用的標記：
| 標記 | 含義 |
|---|---|
| time 或者 t | 當前時間，ISO-8601格式 |
| utctime 或者 utc | UTC時間 |
| uptime 或者 u | 啓動到如今通過的時間，精確到毫秒 |
| timemillis 或者 tm | 毫秒時間戳，至關於System.currentTimeMillis(). |
| uptimemillis 或者 um | 啓動到如今的毫秒時間 |
| timenanos 或者 tn | 納秒時間戳，至關於System.nanoTime() |
| uptimenanos 或者 un | 啓動到如今的納秒時間 |
| hostname 或者 hn | 主機名稱 |
| pid 或者 p | 進程號 |
| tid 或者 ti | 線程號 |
| level 或者 l | 日誌級別 |
| tags 或者 tg | 日誌標籤，參考前面提到的日誌標籤章節 |
假設咱們配置了uptime,level,tags，那麼日誌就會像這個樣子：
[2020-02-26T08:34:12.823+0000][debug][gc,age ] gc(1661) Desired survivor size 167772160 bytes, new threshold 6 (max threshold 6)
4. 將老版本的日誌配置轉換爲新版本的日誌配置
gc相關：
| 原始參數 | 等價新參數以及說明 |
|---|---|
| g1PrintHeapRegions | -Xlog:gc+region=trace |
| gcLogFileSize 和 NumberOfgcLogFiles還有UsegcLogFileRotation | 經過上面提到的 output 和 output-option 來實現 |
| PrintTenuringDistribution | -Xlog:gc+age*=level，參考上面的 gc,age 標籤肯定你想要查看的級別 |
| PrintAdaptiveSizePolicy | -Xlog:gc+ergo*=level, 參考上面的 gc,ergo 標籤章節來決定你想看的日誌級別 |
| Printgc | -Xlog:gc=info或者-Xlog:gc, 打印全部只包含gc標籤的日誌 |
| PrintgcDetails | -Xlog:gc*=info或者-Xlog:gc* |
| PrintgcApplicationConcurrentTime和PrintgcApplicationStoppedTime | -Xlog:safepoint=log或者-Xlog:safepoint,原來是分開的，在新的日誌參數下，標籤都是 safepoint |
| PrintgcTaskTimeStamps | -Xlog:gc+task*=debug |
| PrintHeapAtgc | -Xlog:gc+heap=trace |
| PrintReferencegc | -Xlog:gc+ref*=debug |
| PrintStringDeduplicationStatistics | -Xlog:gc+stringdedup*=debug |
| PrintgcDateStamps | 這個目前經過上面的 decorators 部分配置，對應的是 time 或 t |
| PrintgcCause和PrintgcID | 目前 gc 的 ID 還有 gc 緣由默認就會打出來，不用配置這個了 |
其餘參數：
| 原始參數 | 等價新參數以及說明 |
|---|---|
| TraceExceptions | -Xlog:exceptions=info 打印 JVM 遇到的任何錯誤異常日誌，默認只打印 error 級別的 |
| TraceClassLoadingPreorder | -Xlog:class+preorder=debug |
| TraceClassLoading | -Xlog:class+load=info 打印類加載日誌，info 級別就很足夠 |
| TraceClassUnloading | -Xlog:class+unload=info 打印類卸載日誌，info 級別就很足夠 |
| TraceClassLoadingPreorder | -Xlog:class+preorder=debug |
| TraceClassInitialization | -Xlog:class+init=info |
| TraceClassResolution | -Xlog:class+resolve=debug |
| TraceClassPaths | -Xlog:class+path=info |
| TraceLoaderConstraints | -Xlog:class+loader+constraints=info |
| VerboseVerification | -Xlog:verification=info |
| TraceSafepoint | -Xlog:safepoint=debug |
| TraceSafepointCleanupTime | -Xlog:safepoint+cleanup=info |
| TraceMonitorInflation | -Xlog:monitorinflation=debug |
| TraceBiasedLocking | -Xlog:biasedlocking=level 能夠參考上面提到的 biasedlocking 標籤，根據你想看的信息來配置級別 |
| TraceRedefineClasses | -Xlog:redefine+class*=level |
3、動態修改JVM日誌級別
能夠經過 jcmd 動態修改 JVM 日誌配置， 主要命令是VM.log， 假設咱們的 JVM 進程是22，則能夠經過這個命令查看格式：
jcmd 22 VM.log
結果：
22
Syntax : VM.log [options]
Options: (options must be specified using the <key> or <key>=<value> syntax)
output : [optional] The name or index (#<index>) of output to configure. (STRING, no default value)
output_options : [optional] Options for the output. (STRING, no default value)
what : [optional] Configures what tags to log. (STRING, no default value)
decorators : [optional] Configures which decorators to use. Use 'none' or an empty value to remove all. (STRING, no default value)
disable : [optional] Turns off all logging and clears the log configuration. (BOOLEAN, no default value)
list : [optional] Lists current log configuration. (BOOLEAN, no default value)
rotate : [optional] Rotates all logs. (BOOLEAN, no default value)
查看當前日誌參數配置
假設咱們22的進程，啓動參數中日誌相關的參數是這麼配置的:
-Xlog:gc*=debug:file=/project/log/gc.log:utctime,level,tags:filecount=50,filesize=100M -Xlog:jit+compilation=debug:file=/project/log/jit_compile.log:utctime,level,tags:filecount=10,filesize=100M
執行list命令：
jcmd 22 VM.log list
結果：
22: Log output configuration: #0: stdout all=warning uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/log/gc.log all=off,gc*=debug utctime,level,tags filecount=50,filesize=100M #3: file=/project/log/jit_compile.log all=off,jit+compilation=debug utctime,level,tags filecount=10,filesize=100M
裏面的#0還有#1是咱們以前說的默認JVM日誌配置：
#0: stdout all=warning uptime,level,tags //表明標準輸出中輸出全部標籤的warn級別日誌，格式爲[uptime][level][tags]日誌內容 #1: stderr all=off uptime,level,tags //表明標準錯誤輸出中，不輸出任何日誌
咱們在啓動參數中配置的日誌參數對應的是#2和#3。
讓日誌另起一個文件輸出
jcmd 22 VM.log rotate
22: Command executed successfully
能夠看到#2和#3對應的日誌都另起一個文件繼續輸出
關閉全部日誌，並清理日誌相關參數
jcmd 22 VM.log disable
22: Command executed successfully
jcmd 22 VM.log list
22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags
能夠看出，執行這個命令後，全部的日誌都被關閉，而且參數被清理掉了（連啓動參數配置的日誌參數都不例外）
新增日誌配置輸出
如下參數和咱們啓動參數的-Xlog:gc*=debug:file=/project/log/gc.log:utctime,level,tags:filecount=50,filesize=100M保持一致。
jcmd 22 VM.log output=/project/core/log/gc.log output_options="filecount=50,filesize=100M" decorators="utctime,level,tags" what="gc*=debug"
結果：
22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=debug utctime,level,tags filecount=50,filesize=100M (reconfigured)
因爲以前配置過一次因此這裏有(reconfigured)
修改日誌配置輸出
怎麼區分日誌呢？是經過 output 來惟一區分的（不指定就是stdout）。保持與現有的某個output一致，就是修改配置，可是 output_options 只要設定了，就不能改，只能經過 disable 關閉全部日誌以後從新設置。
例如咱們來修改剛剛的配置級別爲info:
jcmd 22 VM.log output=/project/core/log/gc.log what="gc*=info"
結果：
22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=info uptime,level,tags filecount=50,filesize=100M (reconfigured)
其中，標籤爲包含關係的會自動合併，每次設置是增量設置，而不是全量設置，也就是每次配置的what會附加到現有的輸出當中，從下面幾個例子就能看出來
jcmd 22 VM.log output=/project/core/log/gc.log what="gc+age=info" 22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=info uptime,level,tags filecount=50,filesize=100M (reconfigured)
因爲gc+age其實屬於gc*，因此被合併到了gc*
jcmd 22 VM.log output=/project/core/log/gc.log what="gc+age=debug" 22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=info,age*=debug uptime,level,tags filecount=50,filesize=100M (reconfigured)
將gc+age設置爲 debug 級別，合併變成了gc*=info,age*=debug，能夠推測出，age 只能和 gc 搭配使用
jcmd 22 VM.log output=/project/core/log/gc.log what="gc+alloc+region=debug" 22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=info,age*=debug,alloc+region*=debug uptime,level,tags filecount=50,filesize=100M (reconfigured)
jcmd 22 VM.log output=/project/core/log/gc.log what="gc+heap=debug,gc+heap+region=debug" 22: Command executed successfully jcmd 22 VM.log list 22: Log output configuration: #0: stdout all=off uptime,level,tags #1: stderr all=off uptime,level,tags #2: file=/project/core/log/gc.log all=off,gc*=info,age*=debug,region*=debug,gc+heap=debug,gc+region=info uptime,level,tags filecount=50,filesize=100M (reconfigured)
將gc+alloc+region設置爲 debug ，合併變成了gc*=info,age*=debug；再加上gc+heap=debug,gc+heap+region=debug，合併變成了gc*=info,age*=debug,region*=debug,gc+heap=debug,gc+region=info，能夠看出，region 只有兩種搭配gc+alloc+region和gc+heap+region。
相關文章
- 1. JVM相關 - SafePoint 與 Stop The World 全解(基於OpenJDK 11版本)
- 2. postgresql 日誌參數相關配置解析
- 3. JVM相關參數
- 4. JVM日誌和參數
- 5. JVM日誌和參數的理解
- 6. JVM GC日誌解析
- 7. JVM實用參數（八）GC日誌
- 8. JVM常用GC日誌打印參數
- 9. JVM實用參數 GC日誌
- 10. JVM參數介紹與相關配置
- 更多相關文章...
- • XML 相關技術 - XML 教程
- • XML DOM 解析器 - XML DOM 教程
- • NewSQL-TiDB相關
- • Java Agent入門實戰（三）-JVM Attach原理與使用
相關標籤/搜索
每日一句
-
每一个你不满意的现在，都有一个你没有努力的曾经。
歡迎關注本站公眾號,獲取更多信息
相關文章