麻豆中文字幕,伊人99re,日韩中文字幕精品视频,一级a一级a爱片免费免免高潮按摩 ,婷婷高清av免费在线,国产麻豆成人A,日韩无码影院,日本午夜福利片

本文是一位朋友的作品，之前他向我咨詢了如何給 skywalking 貢獻代碼，我說你搞完了可以寫篇文章。原文發(fā)表在 infoQ：https://xie.infoq.cn/article/9ececbb4179729a8708f4c27e，點擊文章底部閱讀原文直達。

一、Talk is cheap, show you the code

修復了某些場景下線程池插件增強失敗的問題，心急的人可以直接看問題及代碼。

以下是我提交的 issue 和 PR(已經(jīng)被 merged)：

issue: https://github.com/apache/skywalking/issues/10925
pull request: https://github.com/apache/skywalking-java/pull/556

二、背景

最近公司在做全鏈路追蹤，在 agent 這塊使用 skywalking 作為核心實現(xiàn)。同步鏈路 trace 的覆蓋基本上都有 plugin 實現(xiàn)了，對于異步鏈路 trace 這塊開源社區(qū)也已經(jīng)有了線程池的增強 plugin（bootstrap-plugins\apm-jdk-threadpool-plugin.jar）.

首先, 需要把bootstrap-plugins\apm-jdk-threadpool-plugin.jar移動到plugins目錄下.

但是在應用啟動之后的使用過程中，發(fā)現(xiàn)線程池增強失敗了，表現(xiàn)出來的是在線程池中提交的任務打印日志的traceId是空的.

主要環(huán)境說明:

JDK 1.8
skywalking agent 8.14.0
spring boot 2.2.6.RELEASE

三、排查過程

3.1 關(guān)于 AgentClassLoader 的一個發(fā)現(xiàn)

這個發(fā)現(xiàn)純粹是一個巧合, 我發(fā)現(xiàn)在控制臺和 skywalking-api.log 中都有同樣的一份掃描 plugins 目錄中 jar 包的相關(guān)日志

我覺得掃描 plugins 目錄中 jar 包這個事情應該只做一次就行了, 基于這個日志去搜索了一下源碼, 發(fā)現(xiàn)這個動作是在 skywalking 的自定義類加載器AgentClassLoader中的findClass方法中觸發(fā)的, 但是奇怪的是我看到掃描 jar 包這個事情是有緩存的, 理論上只會做一次才對, 為什么觸發(fā)兩次?

在掃描 jar 包的入口代碼處打了斷點調(diào)試, 發(fā)現(xiàn)確實進來了兩次, 但是從 debug 的視圖看到, 兩次進來的AgentClassLoader是 2 個不同的實例。

AgentClassLoader被實例化了 2 次?!

因為本身類的字節(jié)碼增強就是在類加載的階段去做的, 而增強字節(jié)碼主要是靠 plugins 中的 Interceptor, 然后 plugins 中的 class 都是由AgentClassLoader進行加載的, 所以我這里本能的懷疑跟AgentClassLoader被實例化了 2 次有關(guān)系.

帶著這樣的懷疑, 我排查了AgentClassLoader被實例化的地方. 在AgentClassLoader的構(gòu)造器中打了斷點, 發(fā)現(xiàn)第一次是在 premain 方法 agent 剛啟動的時候去實例化了, 第二次是 premain 方法已經(jīng)執(zhí)行完畢, 在 main 方法啟動時第一次加載 plugins 中的 Interceptor 類時去實例化了.

第二次實例化的代碼在InterceptorInstanceLoader類中的load方法

      
      public?class?InterceptorInstanceLoader?{

????public?static?<T>?T?load(String?className,
????????ClassLoader?targetClassLoader)?throws?IllegalAccessException,?InstantiationException,?ClassNotFoundException,?AgentPackageNotFoundException?{
????????if?(targetClassLoader?==?null)?{
????????????targetClassLoader?=?InterceptorInstanceLoader.class.getClassLoader();
????????}
????????String?instanceKey?=?className?+?"_OF_"?+?targetClassLoader.getClass()
???????????????????????????????????????????????????????????????????.getName()?+?"@"?+?Integer.toHexString(targetClassLoader
????????????.hashCode());
????????Object?inst?=?INSTANCE_CACHE.get(instanceKey);
????????if?(inst?==?null)?{
????????????INSTANCE_LOAD_LOCK.lock();
????????????ClassLoader?pluginLoader;
????????????try?{
????????????????pluginLoader?=?EXTEND_PLUGIN_CLASSLOADERS.get(targetClassLoader);
????????????????//?-------------------?關(guān)鍵代碼在這里?-------------------
????????????????if?(pluginLoader?==?null)?{
????????????????????pluginLoader?=?new?AgentClassLoader(targetClassLoader);
????????????????????EXTEND_PLUGIN_CLASSLOADERS.put(targetClassLoader,?pluginLoader);
????????????????}
????????????}?finally?{
????????????????INSTANCE_LOAD_LOCK.unlock();
????????????}
????????????inst?=?Class.forName(className,?true,?pluginLoader).newInstance();
????????????if?(inst?!=?null)?{
????????????????INSTANCE_CACHE.put(instanceKey,?inst);
????????????}
????????}

????????return?(T)?inst;
????}
}

因為已經(jīng)認定了AgentClassLoader就應該是單例的, 這里是重復實例化了, 所以我把這里的源碼改成了復用第一次實例化的AgentClassLoader對象.

重新打包 agent -> 啟動應用 -> 觀察

首先, 掃描 jar 包的日志只剩一份了(在控制臺), 接下來測試線程池的調(diào)用, 發(fā)現(xiàn)這個時候線程池的增強起作用了, 表現(xiàn)為日志中能看到 traceId 的值, 且和主線程中日志的 traceId 一致.

測試代碼:

      
      ????@GetMapping(value?=?"testHello")
????public?String?testHello(@RequestParam("msg")?String?msg){
????????log.info("testHello:{},?traceId:{}",?msg,?org.apache.skywalking.apm.toolkit.trace.TraceContext.traceId());
????????ThreadPoolExecutor?executor?=?new?ThreadPoolExecutor(10,?10,?1000,?TimeUnit.HOURS,?new?ArrayBlockingQueue<>(10));
????????executor.submit(()?->?{
????????????log.info("executor.execute:{},?traceId:{}",?msg,?org.apache.skywalking.apm.toolkit.trace.TraceContext.traceId());
????????});
???????return?"ok";
????}

日志輸出:

      
      2023-06-21?20:38:55.359??INFO?20808?-?[nio-8081-exec-1]?c.ScController???:?testHello:111,?traceId:753241bce942437a9cfd0daea7e21578.65.16873511352010001
2023-06-21?20:38:55.368??INFO?20808?-?[pool-2-thread-2]?c.ScController???:?executor.execute:111,?traceId:753241bce942437a9cfd0daea7e21578.65.16873511352010001

在對AgentClassLoader使用單例后問題解決.

但是問題就此結(jié)束了嗎? 看了下 git commit 歷史記錄, AgentClassLoader的實例化代碼一直都沒有變過, 如果是因為AgentClassLoader的重復實例化問題導致的, 那么有 2 個問題:

線程池插件在 merge 到主干時一定是經(jīng)過測試, 且有測試用例提交的, 為什么官方的測試用例可以通過?
如果是因為AgentClassLoader的重復實例化問題導致的, 那么理論上其他類的增強也會出問題, 但是其他類的增強為什么沒問題呢?

基于上面兩個問題, 我覺得"因為AgentClassLoader的重復實例化"這個原因似乎并不是根因。

也就是說線程池插件一定能生效, but how or when?

3.2 ThreadPoolExecutor 的類加載時機

嘗試用最簡 plugins 配置(因為官方的 test case 都是單個插件單獨測試的, 懷疑是不是插件之間的有一些沖突或者不兼容的問題), 只保留了 tomcat-7.x-8.x-plugin-8.14.0.jar和 apm-jdk-threadpool-plugin-8.14.0.jar

果然，啟動應用之后再調(diào)用線程池的方法，發(fā)現(xiàn) traceId 就正常生效了，也就是插件增強成功。

我想到的是, 字節(jié)碼增強是在類加載的時候觸發(fā)了 transform 操作(注: 類加載完之后也能 retransform, 但是這個不在本文的討論范圍內(nèi)), 會不會是在 skywalking 注冊 transformer 之前ThreadPoolExecutor已經(jīng)被加載到 JVM 中了呢?

帶著這個疑問, 我在應用啟動時增加了-XX:+TraceClassLoading參數(shù), 打印了類加載的具體情況, 如下:

      
      [Opened?C:\Users\xiaqi\.jdks\corretto-1.8.0_372\jre\lib\rt.jar]
[Loaded?java.lang.Object?from?C:\Users\xiaqi\.jdks\corretto-1.8.0_372\jre\lib\rt.jar]
...
[Loaded?java.lang.Runnable?from?C:\Users\xiaqi\.jdks\corretto-1.8.0_372\jre\lib\rt.jar]
[Loaded?java.lang.Thread?from?C:\Users\xiaqi\.jdks\corretto-1.8.0_372\jre\lib\rt.jar]
...
---------------------------------------------------agent?jar包加載---------------------------------------------------
[Loaded?org.apache.skywalking.apm.agent.SkyWalkingAgent?from?file:/D:/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
...
---------------------------------------------------準備注冊transformer---------------------------------------------------------
[Loaded?org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder.AgentBuilder$Transformer?from?file:/C:/Users/xiaqi/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
[Loaded?org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder.AgentBuilder$RedefinitionStrategy$Listener?from?file:/C:/Users/xiaqi/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
[Loaded?org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder.AgentBuilder$Listener?from?file:/C:/Users/xiaqi/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
...
[Loaded?org.apache.skywalking.apm.dependencies.net.bytebuddy.implementation.bind.MethodDelegationBinder$1?from?file:/D:/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
[Loaded?org.apache.skywalking.apm.dependencies.net.bytebuddy.implementation.bind.MethodDelegationBinder$AmbiguityResolver$Resolution?from?file:/D:/IdeaProjects/skywalking-agent/skywalking-agent/skywalking-agent.jar]
---------------------------------------------------注冊transformer結(jié)束---------------------------------------------------------
...
[Loaded?java.util.concurrent.ThreadPoolExecutor?from?C:\Users\xiaqi\.jdks\corretto-1.8.0_372\jre\lib\rt.jar]
...

從上面的日志中可以看出來, ThreadPoolExecutor是在注冊了 transformer 之后, 因此不符合我上面的猜測. 這里順便說一下, 從上面的日志中看得出來, Runnable和Thread這 2 個類都是在 JVM 剛啟動時且 agent 尚未加載時就已經(jīng)被加載到 JVM 中了, 因此這 2 個類想要做字節(jié)碼增強是非常困難的.

既然從類加載的順序上看不出來問題, 我決定看一下第一次使用ThreadPoolExecutor是在具體干什么.

于是我在ThreadPoolExecutor的構(gòu)造器上打了斷點, 正常啟動應用后進入了斷點, 調(diào)用棧如下:

      
      <init>:1310,?ThreadPoolExecutor?(java.util.concurrent)
<init>:1237,?ThreadPoolExecutor?(java.util.concurrent)
<init>:447,?ScheduledThreadPoolExecutor?(java.util.concurrent)
newSingleThreadScheduledExecutor:272,?Executors?(java.util.concurrent)
<init>:66,?FileWriter?(org.apache.skywalking.apm.agent.core.logging.core)
get:56,?FileWriter?(org.apache.skywalking.apm.agent.core.logging.core)
getLogWriter:49,?WriterFactory?(org.apache.skywalking.apm.agent.core.logging.core)
logger:207,?AbstractLogger?(org.apache.skywalking.apm.agent.core.logging.core)
info:72,?AbstractLogger?(org.apache.skywalking.apm.agent.core.logging.core)
doGetJars:197,?AgentClassLoader?(org.apache.skywalking.apm.agent.core.plugin.loader)
getAllJars:177,?AgentClassLoader?(org.apache.skywalking.apm.agent.core.plugin.loader)
findClass:94,?AgentClassLoader?(org.apache.skywalking.apm.agent.core.plugin.loader)
loadClass:418,?ClassLoader?(java.lang)
loadClass:351,?ClassLoader?(java.lang)
forName0:-1,?Class?(java.lang)
forName:348,?Class?(java.lang)
load:71,?InterceptorInstanceLoader?(org.apache.skywalking.apm.agent.core.plugin.loader)
<init>:48,?ConstructorInter?(org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance)
enhanceInstance:124,?ClassEnhancePluginDefine?(org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance)
enhance:116,?AbstractClassEnhancePluginDefine?(org.apache.skywalking.apm.agent.core.plugin)
define:96,?AbstractClassEnhancePluginDefine?(org.apache.skywalking.apm.agent.core.plugin)
transform:167,?SkyWalkingAgent$Transformer?(org.apache.skywalking.apm.agent)
doTransform:12104,?AgentBuilder$Default$ExecutingTransformer?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
transform:12041,?AgentBuilder$Default$ExecutingTransformer?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
access$1800:11758,?AgentBuilder$Default$ExecutingTransformer?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
run:12441,?AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
run:12381,?AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
doPrivileged:-1,?AccessController?(java.security)
doPrivileged:11936,?AgentBuilder$Default$ExecutingTransformer?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
transform:11950,?AgentBuilder$Default$ExecutingTransformer?(org.apache.skywalking.apm.dependencies.net.bytebuddy.agent.builder)
transform:188,?TransformerManager?(sun.instrument)
transform:428,?InstrumentationImpl?(sun.instrument)
defineClass1:-1,?ClassLoader?(java.lang)
defineClass:756,?ClassLoader?(java.lang)
defineClass:142,?SecureClassLoader?(java.security)
defineClass:473,?URLClassLoader?(java.net)
access$100:74,?URLClassLoader?(java.net)
run:369,?URLClassLoader$1?(java.net)
run:363,?URLClassLoader$1?(java.net)
doPrivileged:-1,?AccessController?(java.security)
findClass:362,?URLClassLoader?(java.net)
loadClass:418,?ClassLoader?(java.lang)
loadClass:352,?Launcher$AppClassLoader?(sun.misc)
loadClass:351,?ClassLoader?(java.lang)
registerAnnotationConfigProcessors:170,?AnnotationConfigUtils?(org.springframework.context.annotation)
registerAnnotationConfigProcessors:137,?AnnotationConfigUtils?(org.springframework.context.annotation)
<init>:88,?AnnotatedBeanDefinitionReader?(org.springframework.context.annotation)
<init>:71,?AnnotatedBeanDefinitionReader?(org.springframework.context.annotation)
<init>:73,?AnnotationConfigServletWebServerApplicationContext?(org.springframework.boot.web.servlet.context)
newInstance0:-1,?NativeConstructorAccessorImpl?(sun.reflect)
newInstance:62,?NativeConstructorAccessorImpl?(sun.reflect)
newInstance:45,?DelegatingConstructorAccessorImpl?(sun.reflect)
newInstance:423,?Constructor?(java.lang.reflect)
instantiateClass:204,?BeanUtils?(org.springframework.beans)
instantiateClass:139,?BeanUtils?(org.springframework.beans)
createApplicationContext:588,?SpringApplication?(org.springframework.boot)
run:311,?SpringApplication?(org.springframework.boot)
run:1226,?SpringApplication?(org.springframework.boot)
run:1215,?SpringApplication?(org.springframework.boot)
main:18,?DemoClientApplication?(com.demo.client)

通過調(diào)用棧, 我發(fā)現(xiàn)ThreadPoolExecutor的第一次實例化是在 skywalking 的日志組件FileWriter的實例化中觸發(fā)的.

但是這個調(diào)用棧比較詭異的點就在于觸發(fā)這個的上層調(diào)用是因為引入了 spring 的 plugin 而導致加載 spring 中的AutowiredAnnotationBeanPostProcessor類的時候觸發(fā)了 transform(字節(jié)碼增強), 并且在 transform 階段依賴了ThreadPoolExecutor, 而在對AutowiredAnnotationBeanPostProcessor類的 transform 還沒有結(jié)束時, 似乎在這個時候被依賴的ThreadPoolExecutor類并不會再次觸發(fā) transform(即字節(jié)碼增強).

調(diào)用序列圖:

雖然ThreadPoolExecutor類在這里沒有觸發(fā) transform, 但是類已經(jīng)確確實實被加載到 JVM 了, 而類只會被加載一次, 也就是說后面不會再進行ThreadPoolExecutor的類加載, 也就不會進行字節(jié)碼增強了.

3.3 關(guān)于 JVM 對于 transform 邏輯的猜想

JVM 對于已經(jīng)在類 A 的 transform 階段依賴的類 B 的類加載行為不會再觸發(fā)類 B 的 transform.

猜測這個邏輯是 JVM 為了防止循環(huán)調(diào)用 transform 而導致棧溢出的問題.

假如類 B 也會觸發(fā) transform, 那么可能會出問題的循環(huán)邏輯如下:

類 A 加載 -> 類 A transform

-> transformer 中的類 B 加載 -> 類 B transform(這次類 B 還未完成類加載過程)

-> transformer 中的類 B 加載 -> 類 B transform(這次類 B 還未完成類加載過程)

...

為了進一步驗證這個猜想, 我把 skywalking 中的FileWriter中創(chuàng)建線程池的代碼注釋掉了, 然后再次啟動應用, 發(fā)現(xiàn)線程池插件增強成功, 這個結(jié)果和我的猜想是相符的.

但是這里又有一個疑問:

如果是因為 transform 的邏輯問題, 那么只要存在需要被增強的類, 則一定會有這個問題, 但是為什么上面我驗證了只有 tomcat 插件和線程池插件的時候, 線程池插件是可以正常生效的呢?

后來, 我發(fā)現(xiàn)對于 JDK 中的類的增強和三方類庫中類的增強的邏輯是不一樣的. JDK 中的類的增強在 transform 階段是不會去調(diào)用AgentClassLoader去加載 Interceptor 類, 而是在剛開始的時候就用模板動態(tài)定義好了 Interceptor 類, 并由AppClassLoader完成了加載. 而AppClassLoader是不依賴ThreadPoolExecutor的.

也就是說, 在ThreadPoolExecutor增強之前如果有三方類庫的類先被增強了, 最后ThreadPoolExecutor就會增強失敗, 否則就不會有問題了.(劃重點)

關(guān)于 JDK 中的類的增強的邏輯可以具體看BootstrapInstrumentBoost這個類的實現(xiàn)邏輯.

注: 由于沒有去看 JVM 的源碼, 這個地方的猜想是不嚴謹?shù)? 后面有時間我會再去研究一下 JVM 在這塊的源碼. 如果有經(jīng)驗的同學也可以在后面留言給我說明實際源碼的邏輯是怎么樣的, 不勝感激.

3.4 問題總結(jié)

至此, 所有的疑問都解開了.

上面在 3.1 章節(jié)的最后提出的 2 個問題, 就可以回答了.

Q: 線程池插件在 merge 到主干時一定是經(jīng)過測試, 且有測試用例提交的, 為什么官方的測試用例可以通過?

A: 官方的測試用例是單個 plugin 去測試的, 此時只有ThreadPoolExecutor被增強, 不存在三方類庫增強的問題, 因此可以正常生效.

Q: 如果是因為AgentClassLoader的重復實例化問題導致的, 那么理論上其他類的增強也會出問題, 但是其他類的增強為什么沒問題呢?

A: ThreadPoolExecutor增強失敗的問題主要是因為對三方類庫增強的 transform 階段依賴了ThreadPoolExecutor, 而其他類的增強沒有這樣的情況. 至于把AgentClassLoader改成單例之后為什么就沒問題了, 是因為這樣就不會重復掃描 plugins 目錄中 jar 包, 也就不會打日志, 也就是 transform 階段就不依賴ThreadPoolExecutor了, 因此不會有問題.

四、解決方案

排查原因很曲折, 解決方案很簡單, 我能想到的有 2 種.

AgentClassLoader變成單例, 避免重復掃描 jar 包導致的日志輸出, 從而避免日志組件對ThreadPoolExecutor的依賴.
去除日志組件FileWriter對于ThreadPoolExecutor的依賴, 改為其他的實現(xiàn).

第一種方案, 在和 @吳晟 大佬討論之后被否決了, 原因是大佬說AgentClassLoader的多例是一種簡單的代理模式, 在還沒有深入理解這里的設(shè)計思想的前提下, 還是選擇了尊重權(quán)威.

最后用了第二種方案作為實現(xiàn)思路. FileWriter中ThreadPoolExecutor是為了定時把日志刷到文件中. 首先, 我想到的是用Timer和TimerTask來做替代方案, 但是實際上誰也不知道后面會不會有增強Timer和TimerTask的插件出現(xiàn), 因此最后采用了簡單的 Thread+循環(huán)的方式做了替代方案. 具體的實現(xiàn)代碼可以看我最開始貼的 PR 鏈接.

五、相關(guān)的 issues 和 discussions

從源碼提交記錄來看, 線程池的 plugin 是從 2022 年 4 月第一次提交的, 這一年我也看到有人陸續(xù)反饋了線程池增強失敗的問題, 但是一直沒有得到解決。現(xiàn)在已經(jīng)被我解決啦，在未來的 skywalking agent 8.17.0 版本就能用上了。

以下是相關(guān)的 issues 和 discussions：

https://github.com/apache/skywalking/issues/9425
https://github.com/apache/skywalking/issues/9850
https://github.com/apache/skywalking/issues/10374
https://github.com/apache/skywalking/issues/10685
https://github.com/apache/skywalking/discussions/10207
https://github.com/apache/skywalking/discussions/9888

skywalking 沉了一年的線程池插件 bug 被我解決了

3.1 關(guān)于 AgentClassLoader 的一個發(fā)現(xiàn)

3.2 ThreadPoolExecutor 的類加載時機

3.3 關(guān)于 JVM 對于 transform 邏輯的猜想

3.4 問題總結(jié)

五、相關(guān)的 issues 和 discussions