*作者：* *魯嚴波*

從 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 的方法入口新增日誌：

![1.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/6108c7e9d0684e73a8bd426d028c9862~tplv-k3u1fbpfcp-zoom-1.image "1.png")

加了上面的日誌後，發現問題更加令人頭禿了：

-   沒有報錯的時候，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 的文件，發現它不是完全執行緒安全的：

![2.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/7ca05eefb8ed43069397bd119ac99d29~tplv-k3u1fbpfcp-zoom-1.image "2.png")

通俗的說，iconv 之前，需要先用 iconv_open 開啟一個 iconv_t，而且這個 iconv_t，不支援多執行緒同時使用。

至此，問題已經差不多定位清楚了，因為 jvm 把 iconv_t 寫成了全域性變數，這樣在多個執行緒 append 的時候，就有可能同時呼叫 iconv，導致競態問題。

這兒是第三個坑，iconv 不是執行緒安全的。

## 如何修復

### 先修復 one-java-agent

對於 Java 程式碼，非常容易修改，只需要加一個鎖就可以了：

![3.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/0a26daa91d8b4ff996d985d7eb1c81a2~tplv-k3u1fbpfcp-zoom-1.image "3.png")

但是這兒有一個設計問題，instrument 物件已經在程式碼中到處散落了，現在突然要加一個鎖，幾乎所有用到的地方都要改，程式碼改造成本比較大。

於是最終還是透過 proxy 類來解決：

![4.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/191757c18cf54de3a445d8a04e7dd9e6~tplv-k3u1fbpfcp-zoom-1.image "4.png")

這樣其他地方就只需要使用 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，可以做類似的事情。

1.  pthread_key_create 建立 thread-local storage 區域
1.  pthread_setspecific 用於將值放入 thread-local storage
1.  pthread_getspecific 用於從 thread-local storage 取出值
1.  最重要的，pthread_once 滿足了 pthread_key_t 只能初始化一次的需求。
1.  另外也需要提到的，pthread_once 的第二個引數，就是執行緒結束時的回撥，我們就可以用它來關閉 iconv_t，避免資源洩漏。

總之 pthread 提供了 thread_local 的全生命週期管理。於是，最終程式碼如下，用 make_key 初始化 thread-local storage：

![5.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/df837e96879e4b9cb5fb60bf464ece05~tplv-k3u1fbpfcp-zoom-1.image "5.png")

![6.png](https://p3-juejin.byteimg.com/tos-cn-i-k3u1fbpfcp/cc9b47044c084ade8afd370b3da8d24e~tplv-k3u1fbpfcp-zoom-1.image "6.png")

於是編譯 JDK 之後，打映象、批次重啟數次 pod，就沒有再出現文章開頭提到的問題了。

## 總結

在整個過程中，從 Java 到 JNI/JVMTi，再到 glibc，再到 pthread，踩了很多坑：

-   printf 要加上 fflush 才能保證輸出成功
-   環境變數會影響本地字元編碼轉換
-   iconv 不是執行緒安全的
-   使用 pthread thread-local storage 來實現執行緒區域性變數的全生命週期管理

從這個案例中，沿著呼叫棧、程式碼，逐步還原問題、並提出解決方案，希望大家能對 Java/JVM 多瞭解一點。

***參考連結：***

*[1] 文件：*

**<https:>**

*[2] one-java-agent 修復的連結：*

**<https:>**

*[3] dragonwell 修復的連結：*

**<https:>**

*[4] one-java-agent 給大家帶來了更加方便、無侵入的微服務治理方式：*

**<https:>**

MSE 註冊配置中心專業版首購享 9 折優惠，MSE 雲原生閘道器預付費全規格享  85 折優惠。點選“[此處](https://www.aliyun.com/product/aliware/mse)”，即刻享受優惠！</https:></https:></https:></https:>

Java Agent 踩坑之 appendToSystemClassLoaderSearch 問題

相關文章