打通JVM调优第一条战-JVM日志

不同版本的JVM日志差异是比较大的,所以有必要专门探讨一下,首先我们先来看一下JDK 8里的JVM日志是怎么玩的。

常用参数

这里笔者整理了JDK8一部分相关垃圾收集和运行时的常用参数。

JDK 8垃圾收集相关参数

G1PrintHeapRegions、GCLogFileSize、NumberOfGCLogFiles、PrintAdaptiveSizePolicy、PrintGC、PrintGCApplicationConcurrentTime、PrintGCApplicationStoppedTime、PrintGCCause、PrintGCDateStamps、PrintGCDetails、PrintGCID、PrintGCTaskTimeStamps、PrintGCTimeStamps、PrintHeapAtGC、PrintReferenceGC、PrintStringDeduplicationStatistics、PrintTenuringDistribution、UseGCLogFileRotation

JDK 8运行时常用参数

TraceExceptions、TraceClassLoading、TraceClassLoadingPreorder、TraceClassUnloading、VerboseVerification、TraceClassPaths、TraceClassResolution、TraceClassInitialization、TraceLoaderConstraints、TraceClassLoaderData、TraceSafepointCleanupTime、TraceSafepoint、TraceMonitorInflation、TraceBiasedLocking、TraceRedefineClasses

下面我们来做一个实验,从项目里设置几个参数来打印一个垃圾收集日志玩一玩。

首先,我们把项目JDK切换为JDK8。
在这里插入图片描述
接着,我们从idea编辑启动参数。
在这里插入图片描述
然后把最小堆内存以及最大堆内存都设置成50M
参数设置:

-Xms50m -Xmx50m -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCCause -Xloggc:/Users/weichenglong/Desktop/gclog.log

在这里插入图片描述
简单说一下这些参数,PrintGCDetails:打印垃圾收集的详情;PrintGCDateStamps:打印垃圾收集的日期;PrintGCTimeStamps:打印垃圾收集的时间戳;PrintGCCause:打印造成垃圾收集的原因;Xloggc:把垃圾收集日志打印到的位置。

然后我们启动项目。
我们这时候就已经可以从对应的目录找到生成的日志文件:
在这里插入图片描述
在这里插入图片描述
我们这里已经看到了输出的相关垃圾收集的日志。这里我们先不做分析。

我们再玩一玩JDK 8运行时的常用参数:
在这里插入图片描述
参数设置:

-XX:+TraceClassLoading -XX:+TraceBiasedLocking

让项目在启动时跟踪类加载的情况以及偏向锁的运行情况。

我们运行一下:
在这里插入图片描述
可以看到,控制台疯狂打印一堆类加载的日志,以及偏向锁相关日志。

我们对比先前的垃圾收集日志和这个日志,我们会发现这两种日志格式差异非常大,并且我们从上述文档中可以分析出来,我们需要使用一大堆的参数去控制各种日志的打印,学习成本无疑是非常巨大的。

带上问题,寻找解决办法。

  • 那么这种日志能否简化?
  • 日志打印的格式能否统一起来?

在JDK9之前,两者的答案都是否定的。我们没有办法找到简化的方式,只能像我们刚刚那样,添加一大堆的参数,你也没办法添加统一的日志格式。

但是在JDK9开始,这两个问题都得到了解决。所有相关的配置都可以用Xlog这个参数选项去配置。

并且日志打印的格式都是统一的。官方把这个Xlog叫做“统一日志管理”。

笔者对于Xlog专门做了一份手记,这里笔者拿出来与大家一起分享一下:

Xlog

本文基于JDK11 编写,理论适用于JKD 9及更高版本。

可使用-Xlog选项,启用统一日志管理。
Xlog选项支持的参数如下:

  • -Xlog:使用info级别启用JVM日志
  • -Xlog:help:打印Xlog帮助文档
  • -Xlog:disable:关闭所有日志记录并清除日志框架的所有配置,包括警告和错误的默认配置。
  • -Xlog[:option]:按照命令行上出现的顺序应用多个参数。同一输出的多个参数按其给定顺序覆盖。option的格式为:
    [:[what][:[output][:[decorators][:output-options[,...]]]]]
    
    其中:
    • what:指定level和tag的组合,格式:tag1[+tag2...][*][=level][,...]。除非用了*指定了通配符,否则只有匹配了指定的tag的日志消息才会被分配。
    • output:设置输出类型。默认stdout
    • decorators:使用一系列自定义的装饰器去配置output。缺省的装饰器为uptime、level和tags。
    • output-options:设置Xlog的日志输出选项,格式:
      filecount=file-count filesize=file size with optional K, M or G suffix
      

-Xlog输出

-Xlog支持以下类型的输出:

  • stdout:将输出发送到标准输出
  • stderr:将输出发送到stderr
  • file=filename:将输出发送到文本文件。你还可以让文件按照文件大小轮换,例如每记录10M就轮换,保留5个文件等。默认情况下,最多保留5个20M的文件。可使用filesize=10M,filecouont=5格式去指定文件大小和保留文件数。

装饰器

装饰器是用来装饰消息的,记录与消息有关的信息。可以为每个输出配置一组自定义的装饰器,输出顺序和自定义的顺序相同。缺省的装饰器为uptime、level和tags。none表示禁用所有的装饰器。
下表展示了所有可用的装饰器:

指令描述
timeor tISO-8601格式的当前日期时间
utctimeor utcUniversal Time Coordinated or Coordinated Universal Time
uptimeoruJVM启动了多久,以秒或毫秒为单位
timemillisor tm相当于System.currentTimeMillis()
uptimemillisor umJVM启动以来的毫秒数
timenanosor tn相当于System.nanoTime()
uptimenanosor unJVM启动以来的纳秒数
hostnameor hn主机名
portor p打印进程号
tidorti打印线程号
levelorl与日志消息关联的级别
tagsortg与日志消息关联的标签集

示例

# 示例1:使用info级别记录所有信息到stdout,装饰器使用uptime、level以及tags
# 等价于-Xlog:all=info:stdout:uptimie,levels,tags
-Xlog

# 示例2:以info级别打印使用了gc标签的日志到stdout
-Xlog:gc

# 示例3:使用默认修饰器,info级别,将使用gc或safepoint标签的消息记录到stdout。
-Xlog:gc,safepoint

# 示例4:使用默认修饰器,debug级别,打印同时带有gc和ref标签的日志。
# 仅使用gc或ref的日志不会被记录
-Xlog:gc+ref=debug

# 示例5:不使用装饰器,使用debug级别,将带有gc标签的日志记录到gc.txt中
-Xlog:gc=debug:file=gc.txt:none

#示例6:以trace级别记录所有带有gc标签的日志到gctrace.txt文件集中,该文件集中的文件最大1M,保留5个文件;使用的装饰器是uptimemillis、pids
-Xlog:gc=trace:file=gctrace.txt:uptimemillis,pids:filecount=5,filesize=1024

# 示例7:以trace级别,记录至少带有gc及meta标签的日志到gcmetatrace.txt,同时关闭带有class的日志。某个消息如果同时带有gc、meta及class,将不会被记录,因为class标签被关闭了。
-Xlog:gc+meta*=trace,class*=off:file=gcmetatrace.txt


版权声明:本文为qq_45455361原创文章,遵循CC 4.0 BY-SA版权协议,转载请附上原文出处链接和本声明。