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

问题描述

我决定使用JVMTI来注册JVM中发生的所有异常并构建直方图：
ClassName_method_ExceptionName：count

像这样附加的代理：
任务集-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有时会崩溃。有时候根本不行（〜50之2-4）。

这是从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和本机之间的交互相关的性能问题？当然，使用async-profiler。对应用程序启动进行性能分析时，将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>指定为异步分析器事件。这一次很容易产生一个反向调用树（添加reversed,file=tree.html选项），这样可抛物将按类型和施工现场进行分组。

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异常回调的性能问题的困扰。

奖金

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

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

简而言之，由于所有JVM TI Method函数的速度都很慢，因此最好缓存这些函数的结果，以使代理程序不会为同一方法多次调用JVM TI函数。