最近咱们线上有同学反应，java 服务在接入了支撑预发的 javaagent 今后会呈现缓存的内存增加，去掉 agent 发动今后内存增加正常。所以剖析了一下这个问题，写了这篇文章。
补白：JVM 堆内存最大 1000M
首要会涉及下面这些内容：
- JVM native 内存剖析的通用办法
- JVM Bootstrap ClassLoader 源码剖析
- gdb 的一些调试技巧
- bytebuddy 打破双亲派遣的类加载器
- 不好好干好日志的本分，处处厌恶第一名的 log4j2 是怎么处理过错仓库的
背景介绍
线上全链路预发支撑不能只支撑 http 接口，还得支撑 dubbo rpc、rocketmq、httpclient 等。
- http：针对 http 调用，都会增加一个流量标识的 header：x-ccloud-pre （1-预发流量 2-正式流量），能够支撑okhttp、okhttp3、httpclient 4.x、Spring RestTemplate
- dubbo：预发实例都会增加一个
dubbo.provider.group=gray的参数，经过 group 来区别正式/预发的 provider，agent 内部完结依据流量标识来过滤 provider 的逻辑，而且经过 attachment 把流量标识往下游服务透传。 - RocketMQ：生产者只向本环境的 MQ 投递音讯，顾客只消费本环境 MQ，原理便是依据是否是预发流量，假如是预发请求则即将投递的 topic 修正为预发的 topic。
以上完结都是经过一个 javaagent 来完结的，以完结事务方零代码修正接入。
剖析进程
首要确认过不是堆内存的问题，因此需求用上 NativeMemoryTracking 来剖析 native 内存，所以加上 -XX:NativeMemoryTracking=detail。可是只有这一个东西还不行，还需求结合 pmap、tcmalloc、jemalloc 来剖析。由于内存增加缓慢，这儿开启了一个后台定时履行 pmap 的脚本，用来剖析内存增加在那一块内存区域内，然后放在哪里跑一晚上。
while true
do
sleep 900
name=`date +"%Y_%m_%d_%H_%M_%S"`
echo $name
pmap -x 72 > "pmap_$name.out"
done
经过 diff 比照剖析，找到了内存缓存增加的区域，随后 dump 出这一块内存，dump 的办法能够经过 gdb，也能够经过读取 /proc/$pid/maps 的办法来完结。
经过 dump 出来的内存，首要经过 strings 指令看看里边有没有认识的字符串。
很快发现里边有许多咱们了解的类，比方：
com.cvte.psd.pr.agent.rocketmq.consumer.push.RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper，这个内部类完结了org.apache.rocketmq.client.consumer.listener.MessageListenerOrderly接口，请记住这个接口，后面会频繁呈现。
RocketListenerOrderlyWrapper 做的工作也很简略，便是对 mq 音讯处理进行了署理处理。RocketListenerOrderlyWrapper 完结如下：
import org.apache.rocketmq.client.consumer.listener.MessageListenerOrderly;
public class RocketMqListenerOrderlyWrapperCreator implements PreReleaseWrapperCreator<MessageListenerOrderly> {
public static class RocketListenerOrderlyWrapper implements MessageListenerOrderly {
private MessageListenerOrderly originListener;
private PreReleaseManager preReleaseManager;
public RocketListenerOrderlyWrapper(MessageListenerOrderly originListener, PreReleaseManager preReleaseManager) {
this.originListener = originListener;
}
@Override
public ConsumeOrderlyStatus consumeMessage(List<MessageExt> msgs, ConsumeOrderlyContext context) {
// ...
}
}
}
这个类便是用来包装 RocketMQ 的音讯，来完结预发特性的。
上面 dump 出来的内容究竟都是字符串，仍是 class 文件的常量池的一部分呢？经过 16 进制剖析东西能够进一步剖析。把上面的 dump 文件导入到 010 Editor（www.sweetscape.com/010editor/ ）中，查找 java 字节码的魔数（0xCAFEBABE），能够看这个这段内存中有 2.6W 个 class 文件。
能够删掉第一个 0xCAFEBABE 前面的字节，把剩余的文件当做 class 文件解析。
为什么会有这么多类文件呈现在 native 内存中呢？经过 nmt 能够进一步辅助剖析。这儿能够看到类加载相关的内存 malloc 有 597M 左右，尽管 malloc 不代表真实的运用量（可能 malloc 今后不写，或许用完 free），这个值这么大仍是不太正常。
接下来用 arthas 注入 rocketmq 消费相关的逻辑，发现 agent 中的一个 matches 办法抛出了 IllegalStateException 反常，提示找不到这个类型 org.apache.rocketmq.client.consumer.listener.MessageListenerConcurrently 的类型描述符。
这个 matches 调用是谁调用的呢？经过 arthas 的 stack 指令能够看到是 log4j2 打印日志中发生的调用。
ts=2022-11-10 10:51:49;thread_name=Log4j2-TF-1-AsyncLogger[AsyncContext@18b4aac2]-1;id=2c;is_daemon=true;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@18b4aac2
@com.cvte.psd.pr.agent.PreReleaseAgent$TypeMatcherWrapper.matches()
at com.cvte.psd.pr.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:10304)
at com.cvte.psd.pr.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10263)
at com.cvte.psd.pr.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10186)
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
at java.lang.ClassLoader.findBootstrapClass(ClassLoader.java:-2)
at java.lang.ClassLoader.findBootstrapClassOrNull(ClassLoader.java:1015)
at java.lang.ClassLoader.loadClass(ClassLoader.java:413)
at java.lang.ClassLoader.loadClass(ClassLoader.java:411)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
at org.apache.logging.log4j.core.impl.ThrowableProxyHelper.loadClass(ThrowableProxyHelper.java:209)
at org.apache.logging.log4j.core.impl.ThrowableProxyHelper.toExtendedStackTrace(ThrowableProxyHelper.java:114)
at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
...
at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168)
at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
at java.lang.Thread.run(Thread.java:748)
经过 ThrowableProxyHelper.toExtendedStackTrace 函数的进一步 watch，能够得到抛出的反常仓库是什么。
method=org.apache.logging.log4j.core.impl.ThrowableProxyHelper.toExtendedStackTrace location=AtExit
ts=2022-11-10 15:22:42; [cost=3.189125ms] result=@ArrayList[
@Object[][
@ThrowableProxy[com.wosee.masaike.common.exception.BaseException: 设备：122222222 未获取到绑定信息],
],
@ExtendedStackTraceElement[][
[com.wosee.iot.xxx.UcpDeviceService.getOrgCodeByDeviceId(UcpDeviceService.java:111) ~[app.jar:1.3.2-SNAPSHOT]],
...
[com.wosee.iot.xxx.RocketMqListener.consumeMessage(RocketMqListener.java:35)
[com.cvte.psd.pr.agent.rocketmq.consumer.push.RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper.consumeMessage(RocketMqListenerOrderlyWrapperCreator.java:44) ~[?:?]],
[org.apache.rocketmq.client.impl.consumer.ConsumeMessageOrderlyService$ConsumeRequest.run(ConsumeMessageOrderlyService.java:471)
...
]
能够看到是由于事务代码 mq 消费的 consumeMessage 代码运用 log4j2 打印了日志，在一些状况下会抛出 com.wosee.masike.common.exception.BaseException 事务反常。
问题 0：为什么要 load class
咱们来看触发类加载的 org.apache.logging.log4j.core.impl.ThrowableProxy 类，
这个类有一个注释
A proxy is used to represent a throwable that may not exist in a different class loader or JVM. When an application deserializes a ThrowableProxy, the throwable may not be set, but the throwable’s information is preserved in other fields of the proxy like the message and stack trace.
大意便是这个类为了完结反常信息能够跨网络传输，本地的 LogEvent 可能会传输给别的的 JVM，便于不同 JVM 能够识别这个反常，LogEvent 对日志事件做了封装，对反常做了一些扩展，增加了一些扩展信息，比方反常栈所属的 jar 包、版别等（普通的仓库里没有打印这些）。
ThrowableProxyHelper.toExtendedStackTrace 是上述功用的详细完结。首要做了下面这些工作：
- 拿到办法所属的类，从类中获取 jar 包的位置和版别
- 由于反常栈中没有保存 class 对象，只有类名，因此需求做类加载。（当然也不是一切的都需求，这儿有一个小优化不展开说）
这部分简化过的代码逻辑如下：
static ExtendedStackTraceElement[] toExtendedStackTrace(
final ThrowableProxy src,
final Stack<Class<?>> stack, final Map<String, CacheEntry> map,
final StackTraceElement[] rootTrace,
final StackTraceElement[] stackTrace) {
int stackLength;
final ExtendedStackTraceElement[] extStackTrace = new ExtendedStackTraceElement[stackLength];
Class<?> clazz = stack.isEmpty() ? null : stack.peek();
ClassLoader lastLoader = null;
// 遍历仓库
for (int i = stackLength - 1; i >= 0; --i) {
final StackTraceElement stackTraceElement = stackTrace[i];
final String className = stackTraceElement.getClassName();
// The stack returned from getCurrentStack may be missing entries for java.lang.reflect.Method.invoke()
// and its implementation. The Throwable might also contain stack entries that are no longer
// present as those methods have returned.
ExtendedClassInfo extClassInfo;
final CacheEntry cacheEntry = map.get(className);
// 在缓存列表中直接回来
if (cacheEntry != null) {
final CacheEntry entry = cacheEntry;
extClassInfo = entry.element;
if (entry.loader != null) {
lastLoader = entry.loader;
}
} else {
// 不再则加载类，然后参加缓存列表
final CacheEntry entry = toCacheEntry(ThrowableProxyHelper.loadClass(lastLoader, className), false);
extClassInfo = entry.element;
map.put(className, entry);
if (entry.loader != null) {
lastLoader = entry.loader;
}
}
extStackTrace[i] = new ExtendedStackTraceElement(stackTraceElement, extClassInfo);
}
return extStackTrace;
}
只有在需求获取额定的反常仓库信息时，才会触发这儿的逻辑，正常的打日志是不会呈现的。
比方
logger.error(e);
logger.error("happened service exception! message:{}", e);
第一种办法的输出是
[2022-11-15 08:04:43.316][main][ERROR][com.github.shehanperera.example.MyTest] java.lang.IllegalArgumentException: Object varargs must not be null
这儿不需求仓库信息，不会触发类加载
第二种办法的输出
java.lang.IllegalArgumentException: Object varargs must not be null
at org.apache.commons.lang3.StringUtils.joinWith(StringUtils.java:4880) ~[commons-lang3-3.12.0.jar:3.12.0]
at com.cvte.ya.MyTest.main(MyTest.java:36) [classes/:?]
这种状况下就会触发类加载获取额定的信息，比方这儿的 commons-lang3-3.12.0.jar:3.12.0。
这儿看起来没什么毛病，可是为什么会提示找不到 org.apache.rocketmq.client.consumer.listener.MessageListenerOrderly
这个接口明明是在事务 jar 中是存在的。
经过上面的调用仓库能够发现上面的类加载中，终究类的加载被委托到最顶层的 Bootstrap ClassLoader。
这儿的逻辑就比较清楚了，当初始化类的时分，发现其父类还没有进行过初始化，则需求先触发其父类的初始化。org.apache.rocketmq...MessageListenerOrderly 这个接口的加载被触发是由于需求加载完结类 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper。而且能够推断：com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrder 这个内部类在内存中加载成功了，经过 jvm 解析这个类的字节码，发现它完结了 org.apache.rocketmq...MessageListenerOrderly 接口，所以去测验加载这个接口可是失利了。
这儿就有四个奇怪的问题：
- 为什么
RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper是由 Bootstrap ClassLoader 去加载的 - 为什么
org.apache.rocketmq...MessageListenerOrderly接口加载失利了 - 为什么会导致 native 内存上涨
- 为什么 agent 的功用仍是正常的
问题 1：为什么由 Bootstrap ClassLoader 去加载
这就要再看看双亲派遣相关的常识，引证《深入理解 Java 虚拟机》这本书的原话：
双亲派遣模型的工作进程是：假如一个类加载器收到了类加载的请求，它首要不会自己去测验加载这个类，而是把这个请求派遣给父类加载器去完结，每一个层次的类加载器都是如此，因此一切的加载请求终究都应该传送到最顶层的发动类加载器中，只有当父加载器反应自己无法完结这个加载请求（它的查找范围中没有找到所需的类）时，子加载器才会测验自己去完结加载。
JVM中内置了三个重要的 ClassLoader，分别是 BootstrapClassLoader、ExtensionClassLoader 和 AppClassLoader
这部分源码十分简略，便是一个递归查询。
protected Class<?> loadClass(String name, boolean resolve)
throws ClassNotFoundException
{
synchronized (getClassLoadingLock(name)) {
// First, check if the class has already been loaded
Class<?> c = findLoadedClass(name);
if (c == null) {
try {
if (parent != null) { // 当父类加载器存在时，交给父类去加载
c = parent.loadClass(name, false);
} else { // 父类加载为空时，交给 Bootstrap
c = findBootstrapClassOrNull(name);
}
} catch (ClassNotFoundException e) {
// 假如父类加载器们抛出了 ClassNotFoundException 反常
// 阐明父类加载无法完结加载
}
if (c == null) {
// 当父类加载无法加载时
// 再调用自身的 findClass 来进行类加载
c = findClass(name);
}
}
if (resolve) {
resolveClass(c);
}
return c;
}
}
从上面的仓库能够看出，加载 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper 类确实运用了双亲派遣，经过好几次父类加载器的加载失利，委托给了 Bootstrap。
理论上来说 javaagent 的 jar 不会呈现 Bootstrap 类加载器的 classpath 查找列表里，后面去看了一下 javaagent 的代码，确实咱们为了注入 java 的内部类（线程池等），agent 的 jar 包需求被 Bootstrap 类加载器加载，不然 Bootstrap 类加载器就找不到 javaagent 中的类了。
public class AgentMain {
public static void premain(String agentArguments, Instrumentation instrumentation) {
try {
final File agentJarFile = getAgentJarFile();
try (JarFile jarFile = new JarFile(agentJarFile)) {
// 将 agent 的 jar 包参加到 BootstrapClassLoader
instrumentation.appendToBootstrapClassLoaderSearch(jarFile);
}
} catch (Exception e) {
System.err.println("Failed to start agent");
}
}
}
到这儿就搞清楚了第一个问题，由于 agent 的 jar 被参加 Bootstrap 的 classpath 路径，又由于双亲派遣，导致 Bootstrap ClassLoader 加载成功了 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper。
问题 2：为什么 org.apache.rocketmq...MessageListenerOrderly 接口加载失利了
众所周知，Bootstrap ClassLoader 是由 C++ 完结的，这个类加载器担任加载存放在 <JAVA_HOME>\lib 目录，或许被 -Xbootclasspath 参数所指定的路径中存放的 jar 文件。上面提到在 premain 中咱们把 javaagent 自己的 jar 参加到了 Bootstrap 的 classpath，使得 javaagent 中的 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper 能够被加载，可是 javaagent 中不会将 rocketmq 的 jar 打包到自己的 jar 中，而是选用 provided 的办法，由运用方提供。
<dependency>
<groupId>org.apache.rocketmq</groupId>
<artifactId>rocketmq-client</artifactId>
<version>4.7.0</version>
<scope>provided</scope>
</dependency>
也便是说包含了 org.apache.rocketmq...MessageListenerOrderly 接口的 rocketmq-client-4.7.0.jar 这个 jar 并不会被参加到 Bootstrap 的 classpath 中，因此 MessageListenerOrderly 接口加载失利，
由于完结的接口加载失利，导致 jvm 以为 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper 加载失利。
问题 3：为什么 native 内存会增加
看到这儿，可能许多人现已大概知道是为什么了，先说结论：
Bootstrap ClassLoader 是 C++ 完结的，会把 RocketListenerOrderlyWrapper 文件加载到 native 内存中，然后进行解析，一般来说，Bootstrap ClassLoader 要加载的类，要么加载成功，要么不存在不需求加载。假如加载成功则会将类写入到一个全局的 hashmap 中，下非必须加载时直接回来，不用重复解析类文件。
可是这儿的状况有点特殊，RocketListenerOrderlyWrapper 类加载失利了，可是加载进程发生的 native 内存不会被开释。又由于事务一直在抛反常导致 RocketListenerOrderlyWrapper 类一直测验被加载，可是没有一次能成功，导致 native 内存持续上涨。
接下来咱们用 gdb 调试的办法来验证上面的进程。
首要在 ClassLoader::load_classfile 函数打一个断点，能够看到这儿的逻辑是遍历Bootstrap ClassLoader 的 classpath 测验加载 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper 类。
跟进 ClassPathEntry.open_stream 办法，由于是一个终究进入到了 ClassPathZipEntry::open_stream 中，这个办法从 jar 中读取文件，写入到 buffer 开端的地址中。
经过 x 指令也能够看到 class 文件的魔数，确实加载成功了一个 class 文件。
这块内存确实是 native 内存办理的，咱们能够经过地址去 pmap 中反向查找。
我写了一个小东西 pmapx，来查某个地址处于什么内存地址段区间中，还能够 dump 内存到文件，还能够在内存中查找 16 进制或许字符串，这个东西后面会开释出来。
$ pmapx --type range --pid `pidof java` --addr 0x7f2f98230198 | grep -C 10 0x7f2f98230198
能够看到这块内存是属于典型的 Linux malloc 64M 内存区域（59808+5728=65536KB）。
到这儿，咱们能够看到 com/cvte/psd/pr/agent/rocketmq/consumer/push/RocketMqListenerConcurrentlyWrapperCreator$RocketListenerConcurrentlyWrapper.class 被加载到内存中，接下来便是进行类文件解析了。
在 ClassFileParser::parseClassFile 上打一个断点。
这儿的 cfs 是 ClassFileStream 类型的指针，ClassFileStream 内部包裹了咱们上面加载的类文件内存指针 buffer。
ClassFileStream* cfs = stream();
class ClassFileStream: public ResourceObj {
private:
u1* _buffer_start; // Buffer bottom
u1* _buffer_end; // Buffer top (one past last element)
u1* buffer() const { return _buffer_start; }
}
接下来便是开端解析字节码，判断魔数、版别、常量池等。
随后进入到接下接口的环节，这儿的接口数量为 1，解析到 interface 的类名今后会测验去加载。
接下来调用 SystemDictionary::resolve_instance_class_or_null 来测验加载 org/apache/rocketmq/client/consumer/listener/MessageListenerConcurrently 接口，最终走到了 ClassLoader::load_classfile 来测验加载 org/apache/rocketmq/client/consumer/listener/MessageListenerConcurrently.class 文件，经过 stream 值咱们能够发现，确实在 Bootstrap ClassLoader 中没有找到这个 class 文件。
调用仓库为
至此，native 内存增加的原因也比较清楚了，Bootstrap ClassLoader 每次都被触发读取 com.cvte...RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper.class 字节码到内存中，可是由于依靠的接口加载失利，导致整体加载失利，不会被写入到 SystemDictionary 的全局 hashmap，导致每次都要重新加载写入新的 native 内存。
这个进程如下所示。
验证想法
把 log4j 的日志等级设置为 off 就能够来验证这个问题。
修正今后继续压测内存占用公然稳如老狗，如下图所示。
问题 4：为什么预发 agent 的功用仍是正常的
这儿就要提一下 bytebuddy 的类加载逻辑，bytebuddy 封装了几个常用的 ClassLoader
- ByteArrayClassLoader：byte buddy自定义类加载器，继承自ClassLoader，未重写 loadClass 办法，契合双亲派遣形式
- ByteArrayClassLoader$ChildFirst: ChildFirst 继承了ByteArrayClassLoader，可是重写了 loadClass 办法，破坏了双亲派遣形式。
ChildFirst 类加载的源码如下：
public static class ChildFirst extends ByteArrayClassLoader {
protected Class<?> loadClass(String name, boolean resolve) throws ClassNotFoundException {
// 假如已加载直接回来
Class<?> type = findLoadedClass(name);
if (type != null) {
return type;
}
try {
// 假如没有加载，则先自己测验查找，打破双亲派遣
type = findClass(name);
if (resolve) {
resolveClass(type);
}
return type;
} catch (ClassNotFoundException exception) {
// If an unknown class is loaded, this implementation causes the findClass method of this instance
// to be triggered twice. This is however of minor importance because this would result in a
// ClassNotFoundException what does not alter the outcome.
// 自己实在找不到，就交给父类
return super.loadClass(name, resolve);
}
}
}
com.cvte.psd.pr.agent.rocketmq.consumer.push.RocketMqListenerOrderlyWrapperCreator$RocketListenerOrderlyWrapper 正是由 ByteArrayClassLoader$ChildFirst 这个 classloader 加载的。这个能够经过堆内存 dump 来确认。
ByteArrayClassLoader$ChildFirst 打破了双亲派遣，不会先将类委托给 Bootstrap ClassLoader，也就不会呈现问题，javaagent 功用一切正常。
至此，问题剖析结束。
怎么处理
- 修正 jvm 处理native 内存「泄露」
- 修正 log4j 去掉 ThrowableProxy toExtendedStackTrace 没什么用的逻辑
