通过JVM日志来进行安全点分析

news/2024/7/6 6:34:17

许多事件都可能会导致JVM暂停所有的应用线程。这类暂停又被称为”stop-the-world”(STW)暂停。触发STW暂停最常见的原因就是垃圾回收了(github中的一个例子),但不同的JIT活动(例子),偏向锁擦除(例子),特定的JVMTI操作,以及许多场景也可能会导致应用程序暂停。

应用程序线程可以被安全地停止掉的那个时间点,就叫做安全点。这一术语也通常用来指代SWT暂停。

通常来讲GC日志都是打开的。然而,并非所有安全点的信息都能完整地记录下来。想获取到完整的日志,可以使用下列的JVM选项:

-XX:+PrintGCApplicationStoppedTime 
-XX:+PrintGCApplicationConcurrentTime

从参数名字来看你可能会觉得是与GC相关的,其实不然——打开这些选项能够记录下所有的安全点,而不止是GC暂停的。如果你用上述的选项来运行下这个例子(github源码)

你会在标准输出中看到如下信息:

//java学习交流:737251827  进入可领取学习资源及对十年开发经验大佬提问,免费解答!
Application time: 0.3440086 seconds
Total time for which application threads were stopped: 0.0620105 seconds
Application time: 0.2100691 seconds
Total time for which application threads were stopped: 0.0890223 seconds

很通俗易懂(和GC日志相比来说)——从中你可以得知应用程序在前344毫秒中是在处理实际工作的,然后将所有线程暂停了62毫秒,紧接着又工作了210ms,然后又暂停了89ms。

你还可以将这些选项与GC的选项结合起来使用,比如将上面这个程序加上-XX:+PrintGCDetails 选项后再运行一次,输出则变成这样了;

[Full GC (Ergonomics) [PSYoungGen: 1375253K->0K(1387008K)] [ParOldGen: 2796146K->2049K(1784832K)] 4171400K->2049K(3171840K), [Metaspace: 3134K->3134K(1056768K)], 0.0571841 secs] [Times: user=0.02 sys=0.04, real=0.06 secs]
Total time for which application threads were stopped: 0.0572646 seconds, Stopping threads took: 0.0000088 seconds

综上可知,应用线程被强制暂停了57ms来进行垃圾回收。其中又有8ms是用来等待所有的应用线程都到达安全点。如果我们用同样的选项运行另一个例子(Github源码)的话,输出又变成这样的了:

Total time for which application threads were stopped: 0.0001273 seconds, Stopping threads took: 0.0000196 seconds
Total time for which application threads were stopped: 0.0000648 seconds, Stopping threads took: 0.0000174 seconds

光从这些信息我们无从得知是什么导致的暂停,因为看不出有任何的垃圾回收的活动。如果你想更详细地了解安全点的信息的话,可以使用这组JVM参数:

-XX:+PrintSafepointStatistics  -XX:PrintSafepointStatisticsCount=1

启用这些参数使得JVM会将一些额外的信息记录到标准输出中,大概类似这样:

5.141: RevokeBias [13 0 2] [0 0 0 0 0]0 
Total time for which application threads were stopped: 0.0000782 seconds, Stopping threads took: 0.0000269 seconds

关于安全点的信息是按照如下的顺序进行显示的:

– JVM启动之后所经历的毫秒数(上例中是5.141)

– 触发这次暂停的操作名(RevokeBias)。

如果你看见”no vm operation”,就说明这是一个”保证安全点”。JVM默认每秒会触发一次安全点来处理那些非紧急的排队的操作。GuaranteedSafepointInterval选项可以用来调整这一行为(设置为0的话就会禁用该功能)

– 停在安全点的线程的数量(13)

– 在安全点开始时仍在运行的线程的数量(0)

– 虚拟机操作开始执行前仍处于阻塞状态的线程的数量(2)

– 到达安全点时的各个阶段以及执行操作所花的时间(0)

因此我们可以看出,使用了偏向锁会导致大量的STW暂停,尽管它们只花了几十毫秒。在如今这个大量使用并发的年代,禁用它们也不是什么罕见的事情。

不管怎样,多打印些日志总会减少一些麻烦事的。你可以使用如下的JVM参数:

-XX:+LogVMOutput -XX:LogFile=vm.log

所有的虚拟机日志都会输出到vm.log文件中。如何解读这些日志并做出响应是一个很大的课题,这已经远超本文所讨论的范围了,不过未来我仍会更新一到两篇文章来讲下这个,请拭目以待.


http://www.niftyadmin.cn/n/4352416.html

相关文章

leetcode 任务调度器 python3

给定一个用字符数组表示的 CPU 需要执行的任务列表。其中包含使用大写的 A - Z 字母表示的26 种不同种类的任务。任务可以以任意顺序执行,并且每个任务都可以在 1 个单位时间内执行完。CPU 在任何一个单位时间内都可以执行一个任务,或者在待命状态。 然…

java 上传文件_上传下载文件接口测试

简介在做接口测试的过程中,我们会遇到需要处理文件上传和下载的情况,我们可以使用Jmeter来完成文件的上传下载处理,本文提供两个小示例来展示如何使用Jmeter完成文件上传和文件下载并保存的功能首先来看看普通的Http接口请求的过程&#xff1…

问题管理的重要性

一个人,碰上的问题越多,解决的问题越多;这个人才能进步的越快; 没有问题,那就是在原地踏步。 没有问题才是最大的问题。 转载于:https://www.cnblogs.com/feng9exe/p/6084098.html

python之路——封装、继承和多态

面向对象的三大特性:封装、继承和多态 继承 继承是一种创建新类的方式,在python中,新建的类可以继承一个或多个父类,父类又可称为基类或超类,新建的类称为派生类或子类 单继承和多继承 1 class ParentClass1: #定义父类…

Java字节码浅析(—)

明白Java代码是如何编译成字节码并在JVM上运行的非常重要,这有助于理解程序运行的时候究竟发生了些什么。理解这点不仅能搞清语言特性是如何实现的,并且在做方案讨论的时候能清楚相应的副作用及权衡利弊。 本文介绍了Java代码是如何编译成字节码并在JVM…

leetcode 字符串的排列 python3

给定两个字符串 s1 和 s2,写一个函数来判断 s2 是否包含 s1 的排列。 换句话说,第一个字符串的排列之一是第二个字符串的子串。 示例1:输入: s1 "ab" s2 "eidbaooo" 输出: True 解释: s2 包含 s1 的排列之一 ("ba").示…

python高级应用_Python高级应用程序设计任务

一、主题式网络爬虫设计方案(15分)1.主题式网络爬虫名称关于链家泉州本地租房信息的爬虫2.主题式网络爬虫爬取的内容与数据特征分析2.1爬取的内容租房类型,所属区县,详细地址,房屋面积,房屋朝向,房屋房型,房…

计划的定义与要素

要素:目标、时间、方案。 提出在未来一定时期内要达到的组织目标以及实现目标的方案途径。 http://wiki.mbalib.com/wiki/计划 可以把计划的内容简要地概括为八个方面,即: What(什么)——计划的目的、内容; Who(谁&…