为什么在处理 JVMTI EVENT_EXCEPTION 时，JVM 有时会崩溃或启动缓慢？
Why when processing JVMTI EVENT_EXCEPTION the JVM sometimes crashes or starts slowly?
我决定使用 JVMTI 来注册 JVM 中发生的所有异常并构建直方图：
ClassName_method_ExceptionName:count
这样附加代理：
taskset -c 10,12 java -agentpath:./jni-agent.so ${JVM_OPTION } -cp module.jar org.springframework.boot.loader.PropertiesLauncher &
我将此代码用于 JNI 代理：
enter code here
#include <stdio.h>
#include <jvmti.h>
#include <jni.h>
#include <map>
#include <string>
#include <cstring>
#include "utils.h"
long excCount;
using namespace std;
map<string, long> mapExceptions;
map<string, long> mapContendedThreadStack;
void mapAddException(map<string,long> &inMap, string key){
map<string, long> :: iterator it = inMap.find(key);
if(it == inMap.end()){
inMap.insert(pair<string, long>(key,1));
return;
}
inMap.find(key)->second ++;
return;
}
..
..
void JNICALL ExceptionCallback(jvmtiEnv* jvmti, JNIEnv *env, jthread thread, jmethodID method, jlocation location,
jobject exception, jmethodID catch_method, jlocation catch_location) {
excCount ++;
char *class_name;
jclass exception_class = env->GetObjectClass(exception);
jvmti->GetClassSignature(exception_class, &class_name, NULL);
char* method_name;
jvmti->GetMethodName(method, &method_name, NULL, NULL);
jclass holder;
jvmti->GetMethodDeclaringClass(method, &holder);
char* holder_name;
jvmti->GetClassSignature(holder, &holder_name, NULL);
if(strstr(holder_name, "java/lang") != NULL
|| strstr(holder_name, "java/net") != NULL
|| strstr(holder_name, "sun/reflect") != NULL
|| strstr(holder_name, "org/springframework/boot/loader/jar/JarURLConnection") != NULL
|| strstr(holder_name, "okhttp3/internal/connection/RealConnection") != NULL
|| strstr(holder_name, "okio/AsyncTimeout") != NULL ){
jvmti->Deallocate((unsigned char*) method_name);
jvmti->Deallocate((unsigned char*) holder_name);
jvmti->Deallocate((unsigned char*) class_name);
return;
}
string trimres = trimClassName(convertToString(holder_name, strlen(holder_name)));
char buftotal[1024];
snprintf(buftotal, sizeof(buftotal) - 1, "%s#%s()_%s", trimres.c_str(), method_name, trimClassName(class_name).c_str());
replacechar(buftotal, '/', '.');
//mapAddException(mapExceptions, buftotal); <-- HERE
jvmti->Deallocate((unsigned char*) method_name);
jvmti->Deallocate((unsigned char*) holder_name);
jvmti->Deallocate((unsigned char*) class_name);
}
extern "C" JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *vm, char *options, void *reserved) {
jvmtiCapabilities capabilities;
jvmtiEventCallbacks callbacks;
jvmtiEnv *jvmti;
vm->GetEnv((void **) &jvmti, JVMTI_VERSION_1_0);
printf("\nNative agent loaded by -agent.....\n");
capabilities = {0};
capabilities.can_generate_exception_events = 1;
jvmti->AddCapabilities(&capabilities);
callbacks = {0};
callbacks.Exception = ExceptionCallback;
jvmti->SetEventCallbacks(&callbacks, sizeof(callbacks));
jvmti->SetEventNotificationMode(JVMTI_ENABLE, JVMTI_EVENT_EXCEPTION, NULL);
return 0;
}
带有注释行 mapAddException(...) 的 JVM 启动时间比没有 JNI 代理的时间长得多。
这样可以吗？
我忘了说 - 这是 Spring 带有“Hello World”的引导应用程序一切正常 :)
但是当我取消注释 mapAddException(...) 时，JVM 有时会崩溃。一点也不，有时（~ 2-4 / 50）。
这是从 CrashDump 中截取的：
..
# SIGSEGV (0xb) at pc=0x00007f32781bf0b4, pid=47559, tid=0x00007f31e29e1700
#
# JRE version: Java(TM) SE Runtime Environment (8.0_231-b11) (build 1.8.0_231-b11)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.231-b11 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C [libstdc++.so.6+0x750b4]
..
#
--------------- T H R E A D ---------------
Current thread (0x00007f3275d82000): JavaThread "tomcat-thread-16" daemon [_thread_in_native, id=47682, stack(0x00007f31e28e1000,0x00007f31e29e2000)]
siginfo: si_signo: 11 (SIGSEGV), si_code: 1 (SEGV_MAPERR), si_addr: 0x0000000000000010
Registers:
RAX=0x0000000000000000, RBX=0x00007f3190009340, RCX=0x0000000000000001, RDX=0x00007f3274ba0eb0
RSP=0x00007f31e29dc7c8, RBP=0x00007f327414fea0, RSI=0x00007f32786541d0, RDI=0x00007f327414fea0
R8 =0x0000000000000002, R9 =0x0000000000000030, R10=0x000000000000000c, R11=0x00007f327a316f40
R12=0x00007f31a00504f0, R13=0x00007f32786541c8, R14=0x00007f32786541d0, R15=0x00007f3190009340
RIP=0x00007f32781bf0b4, EFLAGS=0x0000000000010283, CSGSFS=0x0000000000000033, ERR=0x0000000000000004
TRAPNO=0x000000000000000e
....
当前线程在 CrashDump 中每次都不同。
崩溃的原因很简单：你的代码不是线程安全的。
在引发异常的同一线程上调用异常回调。如果多个线程同时抛出异常，回调也会同时被调用。 std::map 不是线程安全的：并发访问可能导致 libstdc++ 内部崩溃。
慢的原因比较有意思
如何分析JVM与native交互的性能问题？当然是 async-profiler。在分析应用程序启动时，将分析器作为代理启动很方便。
java -agentpath:/path/to/libasyncProfiler.so=start,event=cpu,file=out.svg -agentpath:./your-agent.so -cp ...
当我比较有和没有你的代理人的资料时，我注意到一个主要区别。使用代理，左侧有一个明显的 [deoptimization] 块：
为什么会出现反优化？ async-profiler 将再次提供帮助：现在让我们分析一下 Deoptimization::deoptimize 事件。这不是一个真正的事件，这只是 HotSpot JVM 中的一个函数名称（async-profiler 可以跟踪本机函数的调用）。
java -agentpath:/path/to/libasyncProfiler.so=start,event=Deoptimization::deoptimize,file=deopt.svg ...
有超过 8000 个取消优化事件！这里只是图表的一小部分：
大多数去优化源自 exception_handler_for_pc_helper。如果我们查看此函数的 source code，我们会看到一个有趣的注释：
if (JvmtiExport::can_post_on_exceptions()) {
// To ensure correct notification of exception catches and throws
// we have to deoptimize here.
<...>
// We don't really want to deoptimize the nmethod itself since we
// can actually continue in the exception handler ourselves but I
// don't see an easy way to have the desired effect.
Deoptimization::deoptimize_frame(thread, caller_frame.id());
这意味着 - 当 JVM TI 异常通知打开时，每当编译代码中发生异常时，HotSpot 都会强制取消优化！如果异常频繁，这肯定会影响性能。
如何在没有JVM TI开销的情况下分析异常？
此时您可能已经猜到了答案 - 再次使用 async-profiler :) 除了 CPU 和本机函数分析外，它还可以拦截任何 Java 方法调用。
要找到所有产生异常和错误的地方，我们可以截取Throwable个构造函数。为此，请将 java.lang.Throwable.<init> 指定为 async-profiler 事件。这次可以方便地生成反向调用树（添加 reversed,file=tree.html 选项），这样 throwables 将按类型和构造站点分组。
java -agentpath:/path/to/libasyncProfiler.so=start,event=java.lang.Throwable.\<init\>,reverse,file=tree.html ...
这将生成一个交互式 HTML 树，您将在其中找到所有带有计数器和完整堆栈跟踪的异常：
哎呀！一个简单的 Spring 启动应用程序抛出 4700 个异常：其中大部分是 ClassNotFoundException (90%) 和 NoSuchMethodException (7%)。
重要的是，async-profiler使用字节码检测方法跟踪，因此不会受到 JVM TI 异常回调的性能问题的影响。
奖金
第一次分析您的代理时，除了去优化问题外，我还发现了相当数量的堆栈跟踪，其中 CPU 时间花费在您的 ExceptionCallback 调用 GetMethodDeclaringClass和 GetMethodName:
这实际上是 JDK 8 中的性能错误，我在 3 年前报告过：JDK-8185348。最后，它已在 JDK 8u281 中修复。但是JDK9+就没有这个问题了。
简而言之，由于所有 JVM TI 方法函数都很慢，因此缓存这些函数的结果是个好主意，这样代理就不会为同一方法多次调用 JVM TI 函数。
我决定使用 JVMTI 来注册 JVM 中发生的所有异常并构建直方图：
ClassName_method_ExceptionName:count
这样附加代理：
taskset -c 10,12 java -agentpath:./jni-agent.so ${JVM_OPTION } -cp module.jar org.springframework.boot.loader.PropertiesLauncher &
我将此代码用于 JNI 代理：
enter code here
#include <stdio.h>
#include <jvmti.h>
#include <jni.h>
#include <map>
#include <string>
#include <cstring>
#include "utils.h"
long excCount;
using namespace std;
map<string, long> mapExceptions;
map<string, long> mapContendedThreadStack;
void mapAddException(map<string,long> &inMap, string key){
map<string, long> :: iterator it = inMap.find(key);
if(it == inMap.end()){
inMap.insert(pair<string, long>(key,1));
return;
}
inMap.find(key)->second ++;
return;
}
..
..
void JNICALL ExceptionCallback(jvmtiEnv* jvmti, JNIEnv *env, jthread thread, jmethodID method, jlocation location,
jobject exception, jmethodID catch_method, jlocation catch_location) {
excCount ++;
char *class_name;
jclass exception_class = env->GetObjectClass(exception);
jvmti->GetClassSignature(exception_class, &class_name, NULL);
char* method_name;
jvmti->GetMethodName(method, &method_name, NULL, NULL);
jclass holder;
jvmti->GetMethodDeclaringClass(method, &holder);
char* holder_name;
jvmti->GetClassSignature(holder, &holder_name, NULL);
if(strstr(holder_name, "java/lang") != NULL
|| strstr(holder_name, "java/net") != NULL
|| strstr(holder_name, "sun/reflect") != NULL
|| strstr(holder_name, "org/springframework/boot/loader/jar/JarURLConnection") != NULL
|| strstr(holder_name, "okhttp3/internal/connection/RealConnection") != NULL
|| strstr(holder_name, "okio/AsyncTimeout") != NULL ){
jvmti->Deallocate((unsigned char*) method_name);
jvmti->Deallocate((unsigned char*) holder_name);
jvmti->Deallocate((unsigned char*) class_name);
return;
}
string trimres = trimClassName(convertToString(holder_name, strlen(holder_name)));
char buftotal[1024];
snprintf(buftotal, sizeof(buftotal) - 1, "%s#%s()_%s", trimres.c_str(), method_name, trimClassName(class_name).c_str());
replacechar(buftotal, '/', '.');
//mapAddException(mapExceptions, buftotal); <-- HERE
jvmti->Deallocate((unsigned char*) method_name);
jvmti->Deallocate((unsigned char*) holder_name);
jvmti->Deallocate((unsigned char*) class_name);
}
extern "C" JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *vm, char *options, void *reserved) {
jvmtiCapabilities capabilities;
jvmtiEventCallbacks callbacks;
jvmtiEnv *jvmti;
vm->GetEnv((void **) &jvmti, JVMTI_VERSION_1_0);
printf("\nNative agent loaded by -agent.....\n");
capabilities = {0};
capabilities.can_generate_exception_events = 1;
jvmti->AddCapabilities(&capabilities);
callbacks = {0};
callbacks.Exception = ExceptionCallback;
jvmti->SetEventCallbacks(&callbacks, sizeof(callbacks));
jvmti->SetEventNotificationMode(JVMTI_ENABLE, JVMTI_EVENT_EXCEPTION, NULL);
return 0;
}
带有注释行 mapAddException(...) 的 JVM 启动时间比没有 JNI 代理的时间长得多。
这样可以吗？
我忘了说 - 这是 Spring 带有“Hello World”的引导应用程序一切正常 :)
但是当我取消注释 mapAddException(...) 时，JVM 有时会崩溃。一点也不，有时（~ 2-4 / 50）。
这是从 CrashDump 中截取的：
..
# SIGSEGV (0xb) at pc=0x00007f32781bf0b4, pid=47559, tid=0x00007f31e29e1700
#
# JRE version: Java(TM) SE Runtime Environment (8.0_231-b11) (build 1.8.0_231-b11)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.231-b11 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# C [libstdc++.so.6+0x750b4]
..
#
--------------- T H R E A D ---------------
Current thread (0x00007f3275d82000): JavaThread "tomcat-thread-16" daemon [_thread_in_native, id=47682, stack(0x00007f31e28e1000,0x00007f31e29e2000)]
siginfo: si_signo: 11 (SIGSEGV), si_code: 1 (SEGV_MAPERR), si_addr: 0x0000000000000010
Registers:
RAX=0x0000000000000000, RBX=0x00007f3190009340, RCX=0x0000000000000001, RDX=0x00007f3274ba0eb0
RSP=0x00007f31e29dc7c8, RBP=0x00007f327414fea0, RSI=0x00007f32786541d0, RDI=0x00007f327414fea0
R8 =0x0000000000000002, R9 =0x0000000000000030, R10=0x000000000000000c, R11=0x00007f327a316f40
R12=0x00007f31a00504f0, R13=0x00007f32786541c8, R14=0x00007f32786541d0, R15=0x00007f3190009340
RIP=0x00007f32781bf0b4, EFLAGS=0x0000000000010283, CSGSFS=0x0000000000000033, ERR=0x0000000000000004
TRAPNO=0x000000000000000e
....
当前线程在 CrashDump 中每次都不同。
崩溃的原因很简单：你的代码不是线程安全的。
在引发异常的同一线程上调用异常回调。如果多个线程同时抛出异常，回调也会同时被调用。 std::map 不是线程安全的：并发访问可能导致 libstdc++ 内部崩溃。
慢的原因比较有意思
如何分析JVM与native交互的性能问题？当然是 async-profiler。在分析应用程序启动时，将分析器作为代理启动很方便。
java -agentpath:/path/to/libasyncProfiler.so=start,event=cpu,file=out.svg -agentpath:./your-agent.so -cp ...
当我比较有和没有你的代理人的资料时，我注意到一个主要区别。使用代理，左侧有一个明显的 [deoptimization] 块：
为什么会出现反优化？ async-profiler 将再次提供帮助：现在让我们分析一下 Deoptimization::deoptimize 事件。这不是一个真正的事件，这只是 HotSpot JVM 中的一个函数名称（async-profiler 可以跟踪本机函数的调用）。
java -agentpath:/path/to/libasyncProfiler.so=start,event=Deoptimization::deoptimize,file=deopt.svg ...
有超过 8000 个取消优化事件！这里只是图表的一小部分：
大多数去优化源自 exception_handler_for_pc_helper。如果我们查看此函数的 source code，我们会看到一个有趣的注释：
if (JvmtiExport::can_post_on_exceptions()) {
// To ensure correct notification of exception catches and throws
// we have to deoptimize here.
<...>
// We don't really want to deoptimize the nmethod itself since we
// can actually continue in the exception handler ourselves but I
// don't see an easy way to have the desired effect.
Deoptimization::deoptimize_frame(thread, caller_frame.id());
这意味着 - 当 JVM TI 异常通知打开时，每当编译代码中发生异常时，HotSpot 都会强制取消优化！如果异常频繁，这肯定会影响性能。
如何在没有JVM TI开销的情况下分析异常？
此时您可能已经猜到了答案 - 再次使用 async-profiler :) 除了 CPU 和本机函数分析外，它还可以拦截任何 Java 方法调用。
要找到所有产生异常和错误的地方，我们可以截取Throwable个构造函数。为此，请将 java.lang.Throwable.<init> 指定为 async-profiler 事件。这次可以方便地生成反向调用树（添加 reversed,file=tree.html 选项），这样 throwables 将按类型和构造站点分组。
java -agentpath:/path/to/libasyncProfiler.so=start,event=java.lang.Throwable.\<init\>,reverse,file=tree.html ...
这将生成一个交互式 HTML 树，您将在其中找到所有带有计数器和完整堆栈跟踪的异常：
哎呀！一个简单的 Spring 启动应用程序抛出 4700 个异常：其中大部分是 ClassNotFoundException (90%) 和 NoSuchMethodException (7%)。
重要的是，async-profiler使用字节码检测方法跟踪，因此不会受到 JVM TI 异常回调的性能问题的影响。
奖金
第一次分析您的代理时，除了去优化问题外，我还发现了相当数量的堆栈跟踪，其中 CPU 时间花费在您的 ExceptionCallback 调用 GetMethodDeclaringClass和 GetMethodName:
这实际上是 JDK 8 中的性能错误，我在 3 年前报告过：JDK-8185348。最后，它已在 JDK 8u281 中修复。但是JDK9+就没有这个问题了。
简而言之，由于所有 JVM TI 方法函数都很慢，因此缓存这些函数的结果是个好主意，这样代理就不会为同一方法多次调用 JVM TI 函数。