分享近期社区的几个经典的JVM问题
自从9月底我们推出技术社区（https://club.perfma.com ，点击阅读原文跳转到社区）以来，有不少同学活跃在社区里（目前注册用户有了近两万），帮助大家解决各种技术问题，也期望大家都能参与到社区里来。
如果有JVM/性能相关的问题都可以到我们社区里来提问，当然更希望有越来越多的同学能主动帮助大家解决问题，相信我们这个社区经过一段时间的发展，一定会沉淀很多非常有价值的内容帮助到更多的同学，同时也一定会有一些这个领域的KOL诞生出来。
PerfMa技术社区，欢迎大家加入。通过关注我们的微信服务号，当提的问题有回复的时候，会主动进行推送，当关注的人有新的文章发布的时候也会进行推送。
下面挑了近期社区的几个经典的JVM相关的问答分享给大家：
通过GarbageCollectorMXBean获取到的fgc次数耗时与jstat获取到的不一致
一次FullGC，避免新生代（Eden+Survivor）的内容全部放到老年代
jstack命令提示：
target process not responding or HotSpot VM not loaded
关于不同虚拟机版本下的-XX:+TraceClassUnloading
为什么GC日志里新生代的大小比Xmn要小
通过GarbageCollectorMXBean获取到的fgc次数耗时与jstat获取到的不一致
描述：
如题，这是我的jvm参数
-XX:+UseCompressedOops -Xms5g -Xmx5g -XX:PermSize=256M -XX:MaxPermSize=1024m -XX:NewSize=3g -XX:MaxNewSize=3g -XX:+UseCMSInitiatingOccupancyOnly -XX:+PerfDataSaveToFile -XX:SurvivorRatio=10 -Xloggc:/data/dataLogs/gc/gc.log -verbose:gc -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC -XX:+UseCMSCompactAtFullCollection -XX:+CMSClassUnloadingEnabled -XX:+DisableExplicitGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+HeapDumpOnOutOfMemoryErrorjstat采集到的ygc次数与mxbean是一致的，fgc的数量大概是mxbean统计到的两倍，但是不到两倍。
对于耗时，jstat采集到的无论是ygc还是fgc均小于mxbean统计到的数据
回答：
【Rookie_267692】：这是因为CMS收集器在MXBean是在每次发生FGC时只会在Sweeping统计一次，而jstat会在InitialMark阶段统计一次，FinalMark阶段统计一次，这样发生一次CMS gc时就会统计两次，所以次数不一致。
Gc时间在MXBen中统计的是整个gc从开始到结束时间，jstat统计的是gc在每个阶段实际耗费的时间。
一次FullGC，避免新生代（Eden+Survivor）的内容全部放到老年代
描述：
发生一次FullGC，避免新生代（Eden+Survivor）的内容全部放到老年代。这种情况可以避免吗，我觉得ygc之后 即使Survivor放不下，也可以承担一些吧。求解惑
{Heap before GC invocations=619 (full 8): par new generation total 3263424K, used 3086970K [0x0000000680400000, 0x000000075d900000, 0x000000075d900000) eden space 2900864K, 100% used [0x0000000680400000, 0x00000007314e0000, 0x00000007314e0000) from space 362560K, 51% used [0x00000007476f0000, 0x0000000752cae980, 0x000000075d900000) to space 362560K, 0% used [0x00000007314e0000, 0x00000007314e0000, 0x00000007476f0000) concurrent mark-sweep generation total 1612800K, used 961309K [0x000000075d900000, 0x00000007c0000000, 0x00000007c0000000) Metaspace used 210744K, capacity 222745K, committed 222808K, reserved 1249280K class space used 20218K, capacity 22236K, committed 22268K, reserved 1048576K
2019-11-13T03:36:46.611+0800: 14568.064: [GC (Allocation Failure) 14568.064: [ParNew (promotion failed): 3086970K->3081843K(3263424K), 0.4982995 secs]14568.562: [CMS: 961884K->215158K(1612800K), 1.1328686 secs] 4048279K->215158K(4876224K), [Metaspace: 210744K->210744K(1249280K)], 1.6315216 secs] [Times: user=1.67 sys=0.03, real=1.64 secs]
Heap after GC invocations=620 (full 9)Connection Reset By Peer
par new generation total 3263424K, used 0K [0x0000000680400000, 0x000000075d900000, 0x000000075d900000)
eden space 2900864K, 0% used [0x0000000680400000, 0x0000000680400000, 0x00000007314e0000)
from space 362560K, 0% used [0x00000007314e0000, 0x00000007314e0000, 0x00000007476f0000)
to space 362560K, 0% used [0x00000007476f0000, 0x00000007476f0000, 0x000000075d900000)
concurrent mark-sweep generation total 1612800K, used 215158K [0x000000075d900000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 210701K, capacity 222685K, committed 222808K, reserved 1249280K
class space used 20213K, capacity 22226K, committed 22268K, reserved 1048576K
}
回答：
【你假笨】：YGC的过程是从Eden和from space扫描 ，并依次拷贝到to space，如果to space满了再放到old，当然Eden里的可能会引用到from space的，因此并不表示在from space里的一定是在Eden里的对象之后被拷贝
jstack命令提示：target process not responding or HotSpot VM not loaded
描述：
在启动进程的用户下使用jstack命令，没有结果，返回提示如下：
139296: Unable to open socket file: target process not responding or HotSpot VM not loaded
The -F option can be used when the target process is not responding求各位帮看
回答：
【你假笨】：最可能的原因是/tmp目录下的.java_xxx文件被删除了。如果这个情况只能重启了
关于不同虚拟机版本下的-XX:+TraceClassUnloading
在JDK8中尝试重现类卸载的例子, 加入该参数并无法看到控制台有对应的unload日志输出(macos环境jdk1.8.0_161, linux环境jdk1.8.0_91均有尝试);
由于TraceClassUnloading在JDK9后不建议使用了, 被替换为了-Xlog:class+unload=info。
同样的代码在JDK9(macos环境make编译), JDK11下, 在新参数下, 均能看到对应的unload日志。
形如
[0.106s][info][class,unload] unloading class com.github.universe.java.base.Pow 0x0000000800060840为何?
测试代码如下:
import java.io.ByteArrayOutputStream;
import java.io.File;
import java.io.FileInputStream;
import java.io.InputStream;
public class Loop {
public static void main(String[] args) throws Exception{
ClassLoaderB loaderB = new ClassLoaderB("CLB");
loaderB.setPath("/Users/mozilla/core/universe/java-base/target/classes/");
Class<?> clazz = loaderB.loadClass("com.github.universe.java.base.Pow");
Object object = clazz.newInstance();
System.out.println(object);
System.out.println("-----------------");
loaderB = null;
clazz = null;
object = null;
System.gc();
// System.gc();
while (true){
Thread.sleep(100000);
}
}
private static class ClassLoaderA extends ClassLoader{}
private static class ClassLoaderB extends ClassLoader {
private String classLoaderName;
//类的扩展名
private final String fileExtension = ".class";
private String path;
public void setPath(String path) {
this.path = path;
}
public ClassLoaderB(String classLoaderName) {
super();
this.classLoaderName = classLoaderName;
}
public ClassLoaderB(String classLoaderName, ClassLoader parent) {
super(parent);
this.classLoaderName = classLoaderName;
}
@Override
protected Class<?> findClass(String className) throws ClassNotFoundException {
System.out.println("findClass invoked: " + className);
System.out.println("class loader name: " + this.classLoaderName);
byte[] data = this.loadClassDate(className);
return this.defineClass(className, data, 0, data.length);
}
private byte[] loadClassDate(String name) {
InputStream is = null;
byte[] data = null;
ByteArrayOutputStream baos = null;
try {
name = name.replace(".", "/");
is = new FileInputStream(new File(this.path + name + this.fileExtension));
baos = new ByteArrayOutputStream();
int ch = 0;
while ((ch = is.read()) != -1) {
baos.write(ch);
}
data = baos.toByteArray();
} catch (Exception e) {
e.printStackTrace();
} finally {
try {
is.close();
baos.close();
} catch (Exception e) {
e.printStackTrace();
}
}
return data;
}
}
}回答：
【大空翼】：Loop.class这个类的路径也在/Users/mozilla/core/universe/java-base/target/classes/?
Mozilla】回复【大空翼】：如果相同等于CL是活的, 确实不能unload。但是如上所示, 代码了指明让ClassLoaderB去load。而且load成功后我也会打出log在console。而且同一份代码JDK8可以JDK9,11可以就很头疼了。
【大空翼】回复【Mozilla】：ClassLoader的委托类加载机制，并不一定是你指定的这个类加载器加载的，可能委托给父类加载器加载
【Mozilla】回复【大空翼】：一语点醒梦中人。完全忽略了这里。当前的appclassloader的确包含了改地址。然后debug能看到cl的确是app。。至于9和11的jdk是ok的是因为我恰好把目录隔开了。。多谢
为什么GC日志里新生代的大小比Xmn要小
描述：
昨天发现了一个比较奇怪的现象，为什么明明设置了Xmn的具体大小，但是从GC日志看却比这个小，这是为什么呢
``` public class GCTest {
public static void main(String args[]) {
while(true) {
byte[] b = new byte[1024];
}
}
}JVM参数如下：
`-Xmx200M -Xmn60M -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails`
打印的GC日志如下：[GC[ParNew: 49152K->265K(55296K), 0.0018670 secs] 49152K->265K(198656K), 0.0019080 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC[ParNew: 49417K->315K(55296K), 0.0012820 secs] 49417K->315K(198656K), 0.0013050 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[GC[ParNew: 49467K->320K(55296K), 0.0013820 secs] 49467K->320K(198656K), 0.0014070 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[GC[ParNew: 49472K->290K(55296K), 0.0014840 secs] 49472K->290K(198656K), 0.0015120 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
```
从上面GC日志看，新生代的大小为55296K，而我设置了60M，这是为什么呢
回答：
【言风】：新生代的大小应该是eden+form+to 的总大小，我按照你的参数试了下
eden space 49152K,
from space 6144K,
to space 6144K加起来就是61440 也就是60M
而日志里打印的新生代大小应该是eden+一个survivor，也就是新生代可用的内存空间大小
【你假笨】回复【言风】：嗯，回答很对，这里确实是只算了eden+from，可以看下面的代码
void GenCollectedHeap::print_heap_change(size_t prev_used) const {
if (PrintGCDetails && Verbose) {
gclog_or_tty->print(" " SIZE_FORMAT
"->" SIZE_FORMAT
"(" SIZE_FORMAT ")",
prev_used, used(), capacity());
} else {
gclog_or_tty->print(" " SIZE_FORMAT "K"
"->" SIZE_FORMAT "K"
"(" SIZE_FORMAT "K)",
prev_used / K, used() / K, capacity() / K);
}
}其中capacity()的实现：
size_t DefNewGeneration::capacity() const {
return eden()->capacity()
from()->capacity(); // to() is only used during scavenge
}