关于后端:Java-Agent-踩坑之-appendToSystemClassLoaderSearch-问题

4次阅读

共计 5729 个字符,预计需要花费 15 分钟才能阅读完成。

简介:从 Java Agent 报错开始,到 JVM 原理,到 glibc 线程平安,再到 pthread tls,逐渐探索 Java Agent 诡异报错。
作者:鲁严波 从 Java Agent 报错开始,到 JVM 原理,到 glibc 线程平安,再到 pthread tls,逐渐探索 Java Agent 诡异报错。
背景 因为阿里云多个产品都提供了 Java Agent 给用户应用,在多个 Java Agent 一起应用的场景下,造成了总体 Java Agent 耗时减少,各个 Agent 各自存储,导致内存占用、资源耗费减少。
 MSE 发动了 one-java-agent 我的项目,可能协同各个 Java Agent;同时也反对更加高效、不便的字节码注入。其中,各个 Java Agent 作为 one-java-agent 的 plugin,在 premain 阶段是通过多线程启动的形式来加载,从而将启动速度由 O(n) 升高到 O(1),升高了整体 Java Agent 整体的加载工夫。
问题 但最近在新版 Agent 验证过程中,one-java-agent 的 premain 阶段,发现有如下报错:2022-06-15 06:22:47 [oneagent plugin arms-agent start] ERROR c.a.o.plugin.PluginManagerImpl -start plugin error, name: arms-agent
com.alibaba.oneagent.plugin.PluginException: start error, agent jar::/home/admin/.opt/ArmsAgent/plugins/ArmsAgent/arms-bootstrap-1.7.0-SNAPSHOT.jar
at com.alibaba.oneagent.plugin.TraditionalPlugin.start(TraditionalPlugin.java:113)
at com.alibaba.oneagent.plugin.PluginManagerImpl.startOnePlugin(PluginManagerImpl.java:294)
at com.alibaba.oneagent.plugin.PluginManagerImpl.access$200(PluginManagerImpl.java:22)
at com.alibaba.oneagent.plugin.PluginManagerImpl$2.run(PluginManagerImpl.java:325)
at java.lang.Thread.run(Thread.java:750)
Caused by: java.lang.InternalError: null
at sun.instrument.InstrumentationImpl.appendToClassLoaderSearch0(Native Method)
at sun.instrument.InstrumentationImpl.appendToSystemClassLoaderSearch(InstrumentationImpl.java:200)
at com.alibaba.oneagent.plugin.TraditionalPlugin.start(TraditionalPlugin.java:100)
… 4 common frames omitted
2022-06-16 09:51:09 [oneagent plugin ahas-java-agent start] ERROR c.a.o.plugin.PluginManagerImpl -start plugin error, name: ahas-java-agent
com.alibaba.oneagent.plugin.PluginException: start error, agent jar::/home/admin/.opt/ArmsAgent/plugins/ahas-java-agent/ahas-java-agent.jar
at com.alibaba.oneagent.plugin.TraditionalPlugin.start(TraditionalPlugin.java:113)
at com.alibaba.oneagent.plugin.PluginManagerImpl.startOnePlugin(PluginManagerImpl.java:294)
at com.alibaba.oneagent.plugin.PluginManagerImpl.access$200(PluginManagerImpl.java:22)
at com.alibaba.oneagent.plugin.PluginManagerImpl$2.run(PluginManagerImpl.java:325)
at java.lang.Thread.run(Thread.java:855)
Caused by: java.lang.IllegalArgumentException: null
at sun.instrument.InstrumentationImpl.appendToClassLoaderSearch0(Native Method)
at sun.instrument.InstrumentationImpl.appendToSystemClassLoaderSearch(InstrumentationImpl.java:200)
at com.alibaba.oneagent.plugin.TraditionalPlugin.start(TraditionalPlugin.java:100)
… 4 common frames omitted 相熟 Java Agent 的同学可能能留神到,这是调用 Instrumentation.appendToSystemClassLoaderSearch 报错了。但首先 appendToSystemClassLoaderSearch 的门路是存在的;其次,这个报错的实在起因是在 C++ 局部,比拟难排查。但不管怎样,还是要深究下为什么呈现这个谬误。首先咱们梳理下具体的调用流程,上面的剖析都是基于此来剖析的:– Instrumentation.appendToSystemClassLoaderSearch (java)

  • appendToClassLoaderSearch0 (JNI)
    `- appendToClassLoaderSearch
    |- AddToSystemClassLoaderSearch
    | `-create_class_path_zip_entry
    | `-stat
    `-convertUft8ToPlatformString

    `- iconv 打日志、确定现场 因为这个问题在容器环境下,有 10% 的概率呈现,比拟容易复现,于是就用 dragonwell8 的最新代码,加日志,确认下现场。首先在 JNI 的理论入口处,也就是 appendToClassLoaderSearch 的办法入口增加日志:

 加了下面的日志后,发现问题更加令人头秃了:没有报错的时候,appendToClassLoaderSearch entry 会输入。有报错的时候,appendToClassLoaderSearch entry 反而没有输入,没执行到这儿?这个和报错的日志对不上啊,难道是 stacktrace 信息骗了咱们?过了难熬的一早晨后,第二天求教了 dragonwell 的同学,大佬打日志的姿态是这样的:tty->print_cr(“internal error”); 如果下面用不了,再用 printf(“xxx\n”);fflush(stdout); 这样加日志后,果然咱们的日志都能打进去了。这是踩的第一个坑,printf 要加上 fflush 能力保障输入胜利。剖析代码 前面又是一直加日志,最终发现 create_class_path_zip_entry 返回 NULL。找不到对应的 jar 文件?持续排查,发现是 stat 报错,返回 No such file or directory。然而后面也提到了,jarFile 的门路是存在的,难道 stat 不是线程平安的?查了下文档 [1],发现 stat 是线程平安的。于是又回过头来再看,这时候留神到 stat 的门路是不失常的:有的时候门路是空,有的时候门路是 /home/admin/.opt/ArmsAgent/plugins/ahas-java-agent/ahas-java-agent.jarSHOT.jar,从字符开端能够看到,基本上是因为两个字符写到了同一片内存导致的;而且对应字符串长度也变成了一个不法则的数字了。那么问题就很明确了,开始查找这个字符串的生成。这个字符是 convertUft8ToPlatformString 生成的。字符编码转换有问题?于是开始调试 utf8ToPlatform 的逻辑,这时候为了防止频繁加日志、重启容器,所以间接在 ECS 上运行 gdb 调试 jvm。后果发现,在 Linux 下,utf8ToPlatform 就是间接 memcpy,而且 memcpy 的指标地址是在栈上。这怎么看都不太可能有线程平安问题啊?起初认真查了下,发现和环境变量无关,ECS 上编码相干的环境变量是 LANG=en_US.UTF-8,在容器上 centos:7 默认没有这个环境变量,此种状况下,jvm 读到的是 ANSI_X3.4-1968。这儿是第二个坑,环境变量会影响本地编码转换。联合如上景象和代码,发现在容器环境下,还是要通过 iconv,从 UTF-8 转到 ANSI_X3.4-1968 编码的。其实,这儿也能够揣测进去,如果手动在容器中设置了 LANG=en_US.UTF-8,这个问题就不会再呈现。额定的验证也证实了这点。而后又加日志,最终确认是 iconv 的时候,指标字符串写挂了。难道是 iconv 线程不平安?iconv 不是线程平安的!查一下 iconv 的文档,发现它不是齐全线程平安的:

 艰深的说,iconv 之前,须要先用 iconv_open 关上一个 iconv_t,而且这个 iconv_t,不反对多线程同时应用。至此,问题曾经差不多定位分明了,因为 jvm 把 iconv_t 写成了全局变量,这样在多个线程 append 的时候,就有可能同时调用 iconv,导致竞态问题。这儿是第三个坑,iconv 不是线程平安的。如何修复 先修复 one-java-agent 对于 Java 代码,非常容易批改,只须要加一个锁就能够了:

 然而这儿有一个设计问题,instrument 对象曾经在代码中到处散落了,当初忽然要加一个锁,简直所有用到的中央都要改,代码革新老本比拟大。于是最终还是通过 proxy 类来解决:

 

 这样其余中央就只须要应用 InstrumentationWrapper 就能够了,也不会触发这个问题。jvm 要不要修复 而后咱们剖析下 jvm 侧的代码,发现就是因为 iconv_t 不是线程平安的,导致 appendToClassLoaderSearch0 办法不是线程平安的,那能不能优雅的解决掉呢?如果是 Java 程序,间接用 ThreadLoal 来存储 iconv_t 就能解决了。然而 cpp 这边,尽管 C++ 11 反对 thread_local,但首先 jdk8 还没用 C++ 11(这个能够参考 JEP);其次,C++ 11 的也仅仅反对 thread_local 的 set 和 get,thread_local 的初始化、销毁等生命周期治理还不反对,比方没方法在线程完结时主动回收 iconv_t 资源。那咱们就 fallback 到 pthread?因为 pthread 提供了 thread-specific data,能够做相似的事件。pthread_key_create 创立 thread-local storage 区域 pthread_setspecific 用于将值放入 thread-local storagepthread_getspecific 用于从 thread-local storage 取出值最重要的,pthread_once 满足了 pthread_key_t 只能初始化一次的需要。另外也须要提到的,pthread_once 的第二个参数,就是线程完结时的回调,咱们就能够用它来敞开 iconv_t,防止资源透露。总之 pthread 提供了 thread_local 的全生命周期治理。于是,最终代码如下,用 make_key 初始化 thread-local storage:

 于是编译 JDK 之后,打镜像、批量重启数次 pod,就没有再呈现文章结尾提到的问题了。总结 在整个过程中,从 Java 到 JNI/JVMTi,再到 glibc,再到 pthread,踩了很多坑:printf 要加上 fflush 能力保障输入胜利环境变量会影响本地字符编码转换 iconv 不是线程平安的应用 pthread thread-local storage 来实现线程局部变量的全生命周期治理 从这个案例中,沿着调用栈、代码,逐渐还原问题、并提出解决方案,心愿大家能对 Java/JVM 多理解一点。参考链接:[1] 文档:https://pubs.opengroup.org/on… [2] one-java-agent 修复的链接:https://github.com/alibaba/on… [3] dragonwell 修复的链接:https://github.com/alibaba/dr… [4] one-java-agent 给大家带来了更加不便、无侵入的微服务治理形式:https://www.aliyun.com/produc… MSE 注册配置核心专业版首购享 9 折优惠,MSE 云原生网关预付费全规格享  85 折优惠。点击“此处”,即刻享受优惠!

原文链接:http://click.aliyun.com/m/100…
本文为阿里云原创内容,未经容许不得转载。

正文完
 0