关于 openJDK Flight Recorder
Oracle 宣布 Flight Recorder 将在 OpenJDK 开源.具体看下面的链接里面, 说是在 OpenJDK 11 中 release.
https://bugs.openjdk.java.net/browse/JDK-8193393
http://openjdk.java.net/jeps/328
Oracle 宣布 Flight Recorder 将在 OpenJDK 开源.具体看下面的链接里面, 说是在 OpenJDK 11 中 release.
https://bugs.openjdk.java.net/browse/JDK-8193393
http://openjdk.java.net/jeps/328
jcmd 是一个非常有用的命令, 尤其在非桌面环境下. 之前介绍的 jps, jstack, jinfo 的很多功能, 都被整合进了这个最新的 jcmd 命令. 用户通过 jcmd 发送诊断命令给 JVM, JVM 输出相关的信息. 使用 jcmd 时, 要注意和目标 jvm 进程使用同一用户, 否则可能无法使用这个命令.
首先, 我们使用 -h 去查看一下帮助:
LM-SHC-16501315:Downloads xiatian$ jcmd -h
Usage: jcmd <pid | main class> <command ...|PerfCounter.print|-f file>
or: jcmd -l
or: jcmd -h
我们可以通过 jcmd -l 去列出所有的 Java 进程, 这就相当于 jps. 上面的 jcmd -h 就是输出这个帮助文档.
在使用相关命令或者 PerfCounter.print 命令的时候, 可以使用进程 ID 或者 main 类名去匹配. 如果传入的进程 ID 是0, 那么它就认为你要对系统所有 Java 进程执行这个/些命令.
-f 后面跟文件, 意思是让它执行文件里面的所有命令.
Perfcounter.print 是打印当前 Java 进程所拥有的所有 Performance counter 数据.
可以通过如下命令, 去查看当前 Java 进程能执行的 jcmd 命令:
LM-SHC-16501315:Downloads xiatian$ jcmd 42596 help
42596:
The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.check_commercial_features
VM.unlock_commercial_features
ManagementAgent.stop
ManagementAgent.start_local
ManagementAgent.start
GC.rotate_log
Thread.print
GC.class_stats
GC.class_histogram
GC.heap_dump
GC.run_finalization
GC.run
VM.uptime
VM.flags
VM.system_properties
VM.command_line
VM.version
help
还可以进一步通过 help 去查看每个具体命令的帮助, 比如
jcmd $pid help GC.heap_dump
有些命令要求在 JVM 启动时候, 必须先解锁某些 feature 才能用, 比如 JFR 相关的, VM.native_memory等.
//列出 JVM flags
jcmd $pid help VM.flags
jcmd $pid help VM.flags -all // 列出所有
jcmd $pid GC.heap_dump heap.hprof
可能是最新的 JVM 版本 支持使用 -all 选项, 不做full GC, dump 所有对象. 类似于 jmap 不用 live 选项
jcmd $pid GC.heap_dump -all <filename>
//-all : [optional] Dump all objects, including unreachable objects (BOOLEAN, false) Java有 Thread 和 ThreadGroup. ThreadGroup 又可以嵌套. 今天在查看 线程 dump 的时候, 看到2个系统的 thread group: System 和 main. 仔细google 了一下, 貌似JVM 自身的, 比如 GC Daemon, Finalizer, Reference Handler, RMI TCP Accept-0 这些都是 JVM 自带的, 都在 system group 下. main group 是 system group 下的子 group, 它包含: DefaultThreadPool%d%d.
昨天突然遇到一个很奇怪的案例:
一个 JVM, 它使用 CMS GC 算法, 有2G左右内存, 老年代大概1.4G, 年轻代 700M 左右, 在事故之前, 一直都是很正常的年轻代快满的时候, 做年轻代 ParNew GC, 同时老年代过一段时间就做一次 CMS 并发 GC, 每次 CMS GC 回收之后, 老年代大概能有600M 的空间被 free. 这样美妙的状态一直持续到某个时间点, 突然 JVM 狂做 full GC. CPU 飙升到100%, GC overhead 基本到100%.
观察:
首先查看了 gc verbose GC, 通过 log, 我们看到在某个时间点上, 年轻代做了一次回收, 年轻代基本回收完, 之后老年代 CMS 做了一次回收, 回收完之后老年代大概有 (1433600K - 951227K) 471M的空余, 永久代也剩余非常多. 然而, 紧接着 JVM 又做了一次 Full GC, 之后就不停的做 full GC. 到底发生了什么, 在系统年轻代, 老年代, 永久代都有很多剩余的情况下, 还不停的触发 full GC?
猜测及求解:
首先猜测, 是不是代码里面的的 System.gc() 方法被触发? 不可能, 没有重启, 没有人改参数, 关键是如果是这种代码触发的 GC, log 里会表明是 System GC. 被否定.
之后终于有同事指明 log 的疑点:
msg=&st=java.lang.OutOfMemoryError: Java heap space
java.util.Arrays.copyOf(Arrays.java:2219)
java.util.Vector.grow(Vector.java:262)
java.util.Vector.ensureCapacityHelper(Vector.java:242)
java.util.Vector.addElement(Vector.java:616)
这个 Vector 在扩展空间的时候, 导致系统一直做 full GC. 为什么呢? 在 heap dump 里面, 我们可以找到这个 Vector, 它包含非常的元素, 其间接引用的空间已经达到380M 之多. 当它需要更多空间的时候, 他要扩展, 根据 Vector 代码, 如果没有设置每次扩展的大小, 默认扩展到原来的2倍, 也就是说, 他这次扩展要760M 的内存空间. 但是年轻代, 老年代都没有这么多空间供它用了, 他们只好不停的做 full GC. 另外一个相关的问题是, 这个 Vector 是一个所有 request 共享的数据结构, 也就是说每个 request 进来之后, 只向里面加元素, 而不做减元素, 即使第一个尝试尝试扩展空间的 request 失败, 之后的每个 request 同样要做一样的扩展, 所以只好 不停的 full GC, 不停的失败....
那么让我们找几个 Java 的集合类, 来看一下他们是如何扩展空间的:
1) java.util.Vector
Vector 内部有个 capacityIncrement 字段, 它只有可能在 Vector 初始化的时候设置, 如果不设置, 默认是0. 当 Vector 现有申请的空间不够用的时候, 它就自动扩展空间, 这时候, 它会首先检查 capacityIncrement 是不是大于0, 如果大于0, 那么就先添加 capacityIncrement 的数量, 如果添加后能达到要求, 就使用这么多, 如果 capacityIncrement 小于或者等于0, 那么久直接 double 现在的已有空间, 如果 double 后还不够, 那么就直接申请 minCapacity 的空间. 当申请到之后, 就直接 copy 内存到新的空间. 它内部基于连续 Array. 所以如果申请到, 基本做一次全 copy.
下面是 API 文档的摘抄:
Vector can grow or shrink as needed to accommodate adding and removing items. Each vector tries to optimize storage management by maintaining a capacity and a capacityIncrement. The capacity is always at least as large as the vector size; it is usually larger because as components are added to the vector, the vector's storage increases in chunks the size of capacityIncrement.
public void ensureCapacity(int minCapacity)
Increases the capacity of this vector, if necessary, to ensure that it can hold at least the number of components specified by the minimum capacity argument.
If the current capacity of this vector is less than minCapacity, then its capacity is increased by replacing its internal data array, kept in the field elementData, with a larger one. The size of the new data array will be the old size plus capacityIncrement, unless the value of capacityIncrement is less than or equal to zero, in which case the new capacity will be twice the old capacity; but if this new size is still smaller than minCapacity, then the new capacity will be minCapacity.
2) java.util.ArrayList
Array 在初始化的时候, 如果你给他一个 initialCapacity 参数, 那么他就根据你的参数初始化, 否则就初始化为空数组. 当增长需要更多空间的时候, 他也没有那么简单粗暴, 他先尝试增长为原来 capacity 的一半, 如果还不够, 才尝试按照你真实需要的大小去申请空间. 当然最多不能超过 Integer 的最大值.
下面是 API 文档的摘抄:
This class is roughly equivalent to Vector, except that it is unsynchronized. Each ArrayList instance has a capacity. The capacity is the size of the array used to store the elements in the list. It is always at least as large as the list size. As elements are added to an ArrayList, its capacity grows automatically
private void grow(int minCapacity) { // overflow-conscious code int oldCapacity = elementData.length; int newCapacity = oldCapacity + (oldCapacity >> 1); if (newCapacity - minCapacity < 0) newCapacity = minCapacity; if (newCapacity - MAX_ARRAY_SIZE > 0) newCapacity = hugeCapacity(minCapacity); // minCapacity is usually close to size, so this is a win: elementData = Arrays.copyOf(elementData, newCapacity); }
3) java.util.LinkedList
LinkedList 没有这个问题, 它是链表结构, 每次增加的时候, 随便申请一块内存, 添加到列表里面.
4) java.util.HashMap
HashMap 在扩展的时候, 在不超过 Integer 最大值的情况下,也是 double 原来的大小, 所以这也是需要注意的;
5) java.util.HashSet
HashSet 是基于 HashMap 来实现的, 所以和 HashMap 情况一样;
================ 当时的 verbose GC log ================
2018-04-18T23:07:26.246-0700: 2545864.810:
[GC2018-04-18T23:07:26.247-0700: 2545864.810:
[ParNew Desired survivor size 41943040 bytes, new threshold 6 (max 6)2018-04-18T23:07:28.693-0700: 2545867.257:
[GC2018-04-18T23:07:28.694-0700: 2545867.258:
[ParNew Desired survivor size 41943040 bytes, new threshold 6 (max 6)2018-04-18T23:07:28.719-0700: 2545867.283:
[CMS: 1011528K->951227K(1433600K), 5.1650580 secs] 1181233K->951227K(2170880K),
[CMS Perm : 133656K->128154K(524288K)], 5.1909560 secs]
[Times: user=4.63 sys=0.34, real=5.20 secs]
2018-04-18T23:07:33.885-0700: 2545872.449:
[Full GC2018-04-18T23:07:33.886-0700: 2545872.449:
[CMS: 951227K->945587K(1433600K), 4.6014860 secs] 951227K->945587K(2170880K),
[CMS Perm : 128154K->127985K(524288K)], 4.6019310 secs]
[Times: user=3.80 sys=0.80, real=4.60 secs]
2018-04-18T23:07:38.625-0700: 2545877.189:
[GC2018-04-18T23:07:38.626-0700: 2545877.189:
[ParNew Desired survivor size 41943040 bytes, new threshold 6 (max 6)
2018-04-18T23:07:38.644-0700: 2545877.208:
[CMS: 945587K->944299K(1433600K), 4.1096320 secs] 955945K->944299K(2170880K),
[CMS Perm : 127985K->127985K(524288K)], 4.1284360 secs]
[Times: user=6.46 sys=0.01, real=4.12 secs]
2018-04-18T23:07:42.754-0700: 2545881.318:
[Full GC2018-04-18T23:07:42.754-0700: 2545881.318:
[CMS: 944299K->944012K(1433600K), 4.0007380 secs] 944299K->944012K(2170880K),
[CMS Perm : 127985K->127985K(524288K)], 4.0011340 secs]
[Times: user=3.32 sys=0.00, real=4.01 secs]
2018-04-18T23:07:46.788-0700: 2545885.352:
[GC2018-04-18T23:07:46.788-0700: 2545885.352:
[ParNew Desired survivor size 41943040 bytes, new threshold 6 (max 6)
2018-04-18T23:07:46.805-0700: 2545885.368:
[CMS: 944012K->948245K(1433600K), 4.0567560 secs] 964730K->948245K(2170880K),
[CMS Perm : 127985K->127985K(524288K)], 4.0738820 secs]
[Times: user=3.46 sys=0.00, real=4.07 secs]
2018-04-18T23:07:50.862-0700: 2545889.426:
[Full GC2018-04-18T23:07:50.862-0700: 2545889.426:
[CMS: 948245K->947961K(1433600K), 3.9952950 secs] 948245K->947961K(2170880K),
[CMS Perm : 127985K->127985K(524288K)], 3.9956870 secs]
[Times: user=3.31 sys=0.00, real=4.00 secs]
如果一个 web 请求走代理服务器, 那么 client 端是直接和 proxy 建立连接还是和 server 端建立连接?
有代理服务器的话, 代理服务器是如何影响 read timeout 和 connection timeout 的?