为什么在处理 JVMTI EVENT_EXCEPTION 时 JVM 有时会崩溃或启动缓慢？

Question

我决定使用 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 代理的时间长得多。 可以吗？
我忘了说 - 这是带有“Hello World”的 Spring Boot 应用程序，一切正常 :)

但是当我取消注释 mapAddException(...) 时，JVM 有时会崩溃。完全没有，有时（~ 2-4 of 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 的当前线程每次都不同。

Answer 1

崩溃的原因很简单：你的代码不是线程安全的。

在抛出异常的同一线程上调用异常回调。如果多个线程同时抛出异常，回调也会同时被调用。 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 Boot 应用程序会抛出 4700 个异常：其中大部分是 ClassNotFoundException (90%) 和 NoSuchMethodException (7%)。

重要的是，async-profiler 使用字节码检测进行方法跟踪，因此它不会受到 JVM TI 异常回调的性能问题。

奖金

在第一次分析您的代理时，除了去优化问题之外，我还发现了相当数量的堆栈跟踪，其中 CPU 时间花费在您的 ExceptionCallback 调用 GetMethodDeclaringClass 和 GetMethodName：

这实际上是 JDK 8 中的一个性能错误，我在 3 年前报告过：JDK-8185348。最后，它已在 JDK 8u281 中得到修复。但是JDK 9+就没有这个问题了。

简而言之，由于所有 JVM TI Method 函数都很慢，因此最好将这些函数的结果缓存起来，这样代理就不会为同一个方法多次调用 JVM TI 函数。