乐趣区

关于阿里云:Java-Agent-踩坑之-appendToSystemClassLoaderSearch-问题

jiezi

作者：卜比

本文是《容器中的 Java》系列文章之 2/n，欢送关注后续连载 :)。

从 Java Agent 报错开始，到 JVM 原理，到 glibc 线程平安，再到 pthread tls，逐渐探索 Java Agent 诡异报错。

背景

因为阿里云多个产品都提供了 Java Agent 给用户应用，在多个 Java Agent 一起应用的场景下，造成了总体 Java Agent 耗时减少，各个 Agent 各自存储，导致内存占用、资源耗费减少。

所以咱们发动了 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-16 09:51:09 [oneagent plugin a-java-agent start] ERROR c.a.o.plugin.PluginManagerImpl -start plugin error, name: a-java-agent
com.alibaba.oneagent.plugin.PluginException: start error, agent jar::/path/to/one-java-agent/plugins/a-java-agent/a-java-agent-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 b-java-agent start] ERROR c.a.o.plugin.PluginManagerImpl -start plugin error, name: b-java-agent
com.alibaba.oneagent.plugin.PluginException: start error, agent jar::/path/to/one-java-agent/plugins/b-java-agent/b-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 不是线程平安的？

查了下 stat 相干文档 [ 1]，发现 stat 零碎调用是线程平安的。

于是又回过头来再看，这时候留神到 stat 的门路是不失常的：

有的时候门路是空，有的时候门路是 /path/to/b-java-agent/b-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。

这一块能够参考下 nl_langinfo(CODESET) 的文档：https://man7.org/linux/man-pa…

这儿是第二个坑， 环境变量会影响本地编码转换 。

联合如上景象和代码，发现在容器环境下，还是要通过 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 写成了全局变量，这样在多个线程同时调用 appendToClassLoaderSearch0 的时候，就有可能同时调用 iconv，导致竞态问题，把字符串写乱掉。

这儿是第三个坑，iconv 不是线程平安的 。

如何修复

先修复 one-java-agent

对于 Java 代码，非常容易批改，只须要加一个锁就能够了：

然而这儿有一个设计问题，instrument 对象曾经在代码中到处散落了，当初忽然要加一个锁，简直所有用到的中央都要改，代码革新老本比拟大。

于是最终还是通过 proxy 类来解决：

这样其余中央就只须要应用 InstrumentationWrapper 就能够了，也不会触发这个问题。

Java 9+ 的解决

然而留神到，在 JDK9 中，Instrumentation 这个接口减少了 redefineModule/isModifiableModule 办法， 在新版本 JVM 下，上图中的 InstrumentationWrapper 就会因为没有这两个办法而报错。

实质上，是 JDK 对 Instrumentation 这个 interface 做了不兼容的批改，这个改变就很难通过手动 proxy 的形式来兼容。

于是只能应用 JDK Proxy 来实现了，次要代码如图：

这样 one-java-agent 总算残缺的修完了这个 bug 了。

jvm 要不要修复

而后咱们剖析下 jvm 侧的代码，发现其实就是因为 iconv_t 不是线程平安的，导致 appendToClassLoaderSearch0 办法不是线程平安的，那能不能优雅的解决掉这个问题呢？

如果是 Java 程序，咱们能够间接用 ThreadLoal 来存储 iconv_t，就能解决这个问题。

然而 cpp 这边，尽管 C++ 11 反对 thread_local，但首先 jdk8 还没用 C++ 11（这个能够参考 JEP 347 [2 ]）；其次，C++ 11 的也仅仅反对 thread_local 的 set 和 get，thread_local 的初始化、销毁等生命周期治理还不反对，比方没方法在线程完结时主动回收 iconv_t 资源。

那咱们就 fallback 到 pthread？因为 pthread 提供了 thread-specific data，能够做相似的事件。

  1. pthread_key_create 创立 thread-local storage 区域
  2. pthread_setspecific 用于将值放入 thread-local storage
  3. pthread_getspecific 用于从 thread-local storage 取出值
  4. 最重要的，pthread_once 满足了 pthread_key_t 只能初始化一次的需要。
  5. 另外也须要提到的，pthread_once 的第二个参数就是线程完结时的回调，咱们就能够用它来敞开 iconv_t，防止资源透露。

总结一下就是，pthread 提供了 thread_local 的全生命周期治理。

于是，最终代码如下，用 pthread_once 初始化 thread-local storage，而后每个线程调配一个 iconv_t：

接下来，编译 JDK、打镜像、批量重启数次 pod 验证，就没有再呈现文章结尾提到的问题了。

总结

在整个过程中，咱们从 Java 到 JNI/JVMTi，再到 glibc，再到 pthread，踩了很多坑：

  • printf 要加上 fflush 能力保障输入胜利
  • 环境变量会影响本地字符编码转换
  • iconv 不是线程平安的
  • 应用 pthread thread-local storage 来实现线程局部变量的全生命周期治理

从这个案例中，沿着调用栈、代码，逐渐还原问题、并修复问题，心愿大家能通过这个案例，对 Java/JVM 多理解一点。

参考资料

one-java-agent 修复的链接：

https://github.com/alibaba/on…

dragonwell8 修复的链接：

https://github.com/alibaba/dr…

[1] stat 相干文档：

https://pubs.opengroup.org/on…

[2] JEP 347：

https://openjdk.org/jeps/347

退出移动版