12

metaspace会gc吗

 3 years ago
source link: http://javakk.com/854.html
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

[收起] 文章目录

我们将在GC日志中打印元空间的大小。假设我们设置了

-XX:MetaspaceSize=100M

-XX:MaxMetaspaceSize=100M

这意味着一旦metaspace的使用量达到100M就应该触发一个 metaspace fulGC ,但实际上我们从GC日志中发现了这个问题,metaspace只使用了70899KB。

[Full GC (Metadata GC Threshold) [PSYoungGen: 5092K->0K(132096K)] [ParOldGen: 85822K->60451K(181760K)] 90914K->60451K(313856K), [Metaspace: 70899K->70899K(1136640K)], 0.1482072 secs] [Times: user=0.52 sys=0.00, real=0.15 secs]

首先,让我们看看打印这行gc日志的代码,这实际上取决于metaspace使用的大小。

void MetaspaceAux::print_metaspace_change(size_t prev_metadata_used) {
  gclog_or_tty->print(", [Metaspace:");
  if (PrintGCDetails && Verbose) {
    gclog_or_tty->print(" "  SIZE_FORMAT
                        "->" SIZE_FORMAT
                        "("  SIZE_FORMAT ")",
                        prev_metadata_used,
                        used_bytes(),
                        reserved_bytes());
  } else {
    gclog_or_tty->print(" "  SIZE_FORMAT "K"
                        "->" SIZE_FORMAT "K"
                        "("  SIZE_FORMAT "K)",
                        prev_metadata_used/K,
                        used_bytes()/K,
                        reserved_bytes()/K);
  }

  gclog_or_tty->print("]");
}

但是,触发metaspace Full GC的基础不是基于metaspace的实际使用情况,而是基于提交的metaspace的内存大小。

size_t MetaspaceGC::allowed_expansion() {
  size_t committed_bytes = MetaspaceAux::committed_bytes();
  size_t capacity_until_gc = capacity_until_GC();

  assert(capacity_until_gc >= committed_bytes,
        err_msg("capacity_until_gc: " SIZE_FORMAT " < committed_bytes: " SIZE_FORMAT,
                capacity_until_gc, committed_bytes));

  size_t left_until_max  = MaxMetaspaceSize - committed_bytes;
  size_t left_until_GC = capacity_until_gc - committed_bytes;
  size_t left_to_commit = MIN2(left_until_GC, left_until_max);

  return left_to_commit / BytesPerWord;
}

显然,如果我们创建了很多类加载器,每个类加载器都将对应于一个元空间数据结构。我们的元空间的用法是指Metanchunk中的instance。内存大小已分配,但 Metanchunk 并没有全部用完。这个问题被简化了。就像CMS GC的碎片化一样,我们在提交的内存和使用的内存之间有一定的差距, 触发metaspace FullGC是基于提交的内存大小 ,所以用户觉得metaspace没有达到我们的阈值触发Full GC,这似乎很可疑。

因此,我想提出一个小建议,对于全GC的场景,在打印metaspace的GC日志时,会更直接地打印提交内存大小而不是已用内存大小,这样可以让用户更清楚地看到,并且发现元空间的阈值已经达到了完全GC的触发器。

修改后的日志更明显,当到达100M时确实会触发,但它会带来另一个缺点,即我们不知道真正使用了多少元空间。

[Full GC (Metadata GC Threshold) [PSYoungGen: 5092K->0K(132096K)] [ParOldGen: 81395K->60429K(181248K)] 86488K->60429K(313344K), [Metaspace: 102400K->70599K(1136640K)], 0.1330421 secs] [Times: user=0.46 sys=0.00, real=0.13 secs]

这个问题会对各种GC策略产生一些影响,如下 metaspace gc 案例:

定位过程:

-Xloggc:/dev/shm/gc20190226084714.log
2019-02-26T08:24:09.252+0800: 391942.779: [Full GC (Metadata GC Threshold) 2019-02-26T08:24:09.252+0800: 391942.779: [CMS: 361366K->361612K(10485760K), 1.1662525 secs] 609428K->361612K(16148096K), [Metaspace: 187649K->187649K(1572864K)], 1.1694997 secs] [Times: user=1.24 sys=0.00, real=1.17 secs]
2019-02-26T08:24:10.421+0800: 391943.948: [Full GC (Last ditch collection) 2019-02-26T08:24:10.422+0800: 391943.948: [CMS: 361612K->361518K(10485760K), 1.1508390 secs] 361612K->361518K(16148096K), [Metaspace: 187608K->187608K(1572864K)], 1.1540049 secs] [Times: user=1.16 sys=0.00, real=1.15 secs]
2019-02-26T08:24:11.576+0800: 391945.103: Total time for which application threads were stopped: 2.3287421 seconds, Stopping threads took: 0.0001573 seconds

向打印类加载添加JVM参数:

# Add parameters to the catalina.sh script and restart. After restart, view the class loading in the tomcat/logs/catalina.out file log

JAVA_OPTS="$JAVA_OPTS -XX:+TraceClassLoading -XX:+TraceClassUnloading"

4. 查看catalina.out日志中,我们发现大量重复的反射类加载:

[Loaded sun.reflect.GeneratedConstructorAccessor72 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor73 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor74 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor75 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor76 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor77 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor78 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedConstructorAccessor79 from __JVM_DefineClass__]

5. 由于Spring框架的动态代理,加载的类是反射类。不确定类是否有重复加载。有必要查看特定的动态代理类或方法。

6. 手动编写类筛选器以在转储元空间中加载类文件。

1) 写入方法访问筛选器:

import sun.jvm.hotspot.oops.InstanceKlass;
import sun.jvm.hotspot.tools.jcore.ClassFilter;

public class MethodAccessorFilter implements ClassFilter {

    @Override
    public boolean canInclude(InstanceKlass instanceKlass) {
        String klassName = instanceKlass.getName().asString();
        
        // Sun/reflect/Delegating ClassLoader can be replaced by a package path or class that requires Dump
        return klassName.startsWith("sun/reflect/DelegatingClassLoader");
    }
}

2) 编译方法访问筛选器:

$ javac -classpath $JAVA_HOME/lib/sa-jdi.jar  MethodAccessorFilter.java

3) 转储指定的类或包:

$ java -classpath ".:$JAVA_HOME/lib/sa-jdi.jar" -Dsun.jvm.hotspot.tools.jcore.filter=MethodAccessorFilter sun.jvm.hotspot.tools.jcore.ClassDump 269932
# Note: dump output files are stored in the current directory, such as:. / sun / reflect / Delegating Class Loader XX. class

4) 找到大量的重复类(很多是例外情况需要根据自己的项目情况和经验判断),反编译这个类的类文件。

$ javap -verbose GeneratedMethodAccessor99.class

# Find the exact location of invokevirtual

5) 查找反射调用的类构造或方法(以下是反射方法的示例):

find ./ -name "GeneratedMethodAccessor*" | xargs javap -verbose | grep "invokevirtual #10" | grep "com.pjbest" >> /tmp/invokevirtual.txt

7. 查看实际代理的方法或类,并结合代码进一步分析元空间持续增长的根本原因。

事故原因如下:

事故是由于 MapperFactory 使用不当造成的。在使用 MapperFactory 时,需要维护单例或直接使用静态方法:

具有元空间泄漏可能性的代码:

RFvYbmq.png!mobile

正确代码:

2mMb6fu.png!mobile

总结

元空间溢出有很多原因。本文以spring框架为例进行分析。需要了解类加载原理和spring动态代理机制,然后利用工具进行分析,最后用代码找出问题的根源。


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK