导语：
正文作家为处置一个JDK本能题目，从仓库领会，到GC领会，再到Safepoint因为领会，最后定位到题目根因与所用的JDK本子相关。并整治成文，与一切Java关系开拓的同窗瓜分此次体味。
01 题目来了
笔者近期在处事中遇到如许一个题目：某存户新上线了一个Elasticsearch运用，但运转一段功夫后就变的更加慢，以至查问超时。重启后效劳回复，但每隔3～4钟点后题目重现。
对准这个题目，我身边的共事也维护做了大略领会，创造生存洪量Merge的线程，该当如何办呢？按照我之前定位题目的体味，普遍经过Thread Dump日记领会，就能找到题目因为的精确目标，而后再领会该题目连接反复的因为。依照这个思绪，题目领会起来该当不算搀杂。But，厥后剧情仍旧展示了妨碍。
02 迷惑的仓库日记
因搜集分隔因为，只能由存户共同获得Thread Dump日记。并跟存户夸大了获得Thread Dump日记的本领，每个节点每隔几秒获得一次，输入到一个独力的文献中。集群波及到三个节点，咱们姑且将这三个节点称之为39，158， 211。题目复现后，拿到了第一批Thread Dump文献：
从文献的巨细，可简单看出39节点大约率是一个题目节点，它的Thread Dump日记鲜明大出很多：查问变慢大概卡死，常常展现为洪量的Worker Thread劳累，也即是说，活泼线程数目明显增加。而在ES(Elasticsearch，以次简称为ES)的默许查问动作下，只有有一个节点展示题目，就会让所有查问受连累。
那么咱们先对三个节点任选的1个Thread Dump文献的线程总体情景举行比较：
节点称呼39158211线程总额366341282RUNNABLE264221162WAITING648892TIME_WAITING283228BLOCKED1000再按线程池举行分门别类统计：
节点称呼39158211Lucene Merge Thread7700http_server_worker646464search494949transport_client_boss286430bulk323232generic1564transport_server_worker275529refresh10510management523warmer555flush555others495451不妨创造：39节点上的Lucene Merge Thread鲜明偏多，而其它两个节点没有任何Merge的线程。
再对39节点的Thread Dump文献举行深刻领会，创造的特殊点归纳如次：
1. Lucene Merge Thread到达77个，个中一个线程的挪用栈如次所示：
2. 有8个线程在比赛锁定ExpiringCache：
3. 有8个线程都在做HashMap#hash计划：
局面第11中学提到了有77个同声在做Merge的线程，但没辙决定那些Merge工作是同声被触发的，仍旧由于体例处置过慢渐渐积聚成如许的状况。不管怎样这像是一条要害线索。再商量到这是一个新上线的运用，对于情况消息与运用模样的调查研究同样要害：
集群公有3个节点，暂时公有500+个Indices。每个节点上写活泼的分片数在70个安排。按佃户创造Index，每个佃户每天创造3个Indices。上线前期，写入含糊量较低。每个索引在每秒钟Flush成的Segment在KB~数MB之间。我发端质疑这种特出的运用办法：集群中生存多个写活泼的索引，但每秒钟的写入量都偏小，在KB至数MB级别。这表示着，Flush大概都是周期性触发，而不是胜过预设阈值后触发。这种写入办法，会引导爆发洪量的小文献。取样查看了几个索引中新爆发的Segment文献，简直每一次天生的文献都特殊小。
对于第2点局面，我刻意观赏了java.io.UnixFileSystem的源码：
UnixFileSystem中须要对一个新文献的路途依照操纵体例规范举行规范化。规范化的截止寄存在ExpiringCache东西中。多个线程都在争相挪用ExpiringCache#put操纵，这侧面反应了文献列表的高频变革，这证明体例中生存高频的Flush和Merge操纵。
这加重了我对于运用模样的质疑：”小雨绵绵”式的写入，被迫触发Flush，即使周期沟通，表示着同声Flush，多个Shard同声Merge的几率变大。
所以，我发端在尝试情况中模仿这种运用办法，创造一致的分片数目，遏制写入频次。安置让尝试步调起码运转一天的功夫，查看能否不妨复现此题目。在步调运转的同声，我连接观察Thread Dump日记。
第3点局面中，只是是做一次hash计划，却展现出更加慢的格式。即使将这三点局面归纳起来，不妨创造一切的挪用点都在做CPU计划。按说说，CPU该当更加的劳累。
等题目在当场复现的功夫，存户扶助获得了CPU运用率与负载消息，截止表露CPU资源特殊闲。在这之前，共事也调查研究过IO资源，也利害常闲的。这废除了体例资源上面的感化。此时也创造，每一次复现的节点是随机的，与呆板无干。
一天往日后，在当地尝试情况中，题目没能复现出来。纵然运用模样不优美，但却不像是题目的毛病地方。
03 诡异的STW阻碍
经过jstack吩咐获得Thread Dump日记时，须要让JVM过程加入Safepoint，十分于所有过程先被挂起。获得到的Thread Dump日记，也凑巧是过程挂起时每个线程的刹时状况。
一切劳累的线程都恰巧在做CPU计划，但CPU并不劳累。这提醒须要进一步伐查GC日记。
当场运用并未打开GC日记。商量到题目暂时尚未复现，经过jstat东西来察看GC度数与GC统计功夫的意旨不太大。让当场职员在jvm.options中手动增添了如次参数来打开GC日记：
8:-XX:+PrintGCDetails8:-XX:+PrintGCDateStamps8:-XX:+PrintTenuringDistribution8:-XX:+PrintGCApplicationStoppedTime8:-Xloggc:logs/gc.log8:-XX:+UseGCLogFileRotation8:-XX:NumberOfGCLogFiles=328:-XX:GCLogFileSize=32m增添PrintGCApplicationStoppedTime是为了将每一次JVM过程爆发的STW(Stop-The-World)阻碍记载在GC日记中。常常，该类STW阻碍都是因GC惹起，也大概与偏差锁相关。
方才重启，当场职员把GC日记tail的截止发了过来，这是为了确认摆设已奏效。诡异的是，方才重启的过程果然在不停的打字与印刷STW日记：
对于STW日记(”…Total time for which application threads were stopped…”)，这边有需要大略证明一下：
JVM偶尔须要实行少许全部操纵，典范如GC、偏差锁接收，此时须要休憩一切正在运转的Thread，这须要依附于JVM的Safepoint体制，Safepoint就比如一条大街道上树立的红灯。JVM每一次加入STW（Stop-The-World）阶段，城市打字与印刷如许的一条龙日记：
2020-09-10T13:59:43.210+0800: 73032.559: Total time for which application threads were stopped: 0.0002853 seconds, Stopping threads took: 0.0000217 seconds在这行日记中，提醒了STW阶段连接的功夫为0.0002853秒，而叫停一切的线程(Stopping threads)耗费了0.0000217秒，前者包括了后者。常常，Stopping threads的功夫占比极小，即使过长的话大概与代码实行详细相关，这边然而多打开。
回到题目，一发端就打字与印刷洪量的STW日记，简单想到与偏差锁接收相关。直到题目再次复当前，拿到了3个节点的完备的GC日记，创造不管是YGC仍旧FGC，触发的频次都很低，这废除了GC上面的感化。
展示的洪量STW日记，使我认识到该局面极不对理。有同窗提出质疑，每一次阻碍功夫很短啊？写了一个大略的东西，对每一秒钟的STW阻碍频次、阻碍总功夫做了统计：
统计截止表露：
平常每秒钟都有5秒安排的阻碍。在11:29～11:30之间，阻碍频次陡增，这凑巧是题目局面发端展示的功夫段。每秒钟的阻碍总功夫以至高达20～30秒。这就比如，一段1公里的街道上，平常是遇不见任何红绿灯的，此刻遽然减少了几十个红绿灯，简直是让人解体。那些阻碍很好的证明了“一切的线程都在做CPU计划，但是CPU资源很闲”的局面。
04 对于Safepoint的观察
Safepoint有多种典型，为了确认Safepoint的简直典型，连接让当场同窗扶助，在jvm.options中增添如次参数，翻开JVM日记：
-XX:+PrintSafepointStatistics-XX:PrintSafepointStatisticsCount=10-XX:+UnlockDiagnosticVMOptions-XX:-DisplayVMOutput-XX:+LogVMOutput-XX:LogFile=<vm_log_path>等候题目再次复现的进程中，我鉴于ES运转日记国民党中央执行委员会调查统计局计了每一秒钟的读写乞求频次：
读写乞求度数是对立稳固的，这废除了用户乞求陡增上面的因为。
拿到JVM日记时，看到洪量的Safepoint典型为ForceSafepoint：
而偏差锁接收关系的Safepoint却该当是长如许的：
这让我迷惑了。发端在网上探求ForceSafepoint的触发因为，截止，宝山空回。
察看hotspot的源码，创造至罕见5种关系场景：
看来，ForceSafepoint是一个“杂烩”，就像统计图中的“Others”一项。从这边发端，我将JDK介入到了“中心疑惑人”清单中。
连接领会JVM日记。在每一条Safepoint日记中，同声记载了其时的线程总额(threads: total一列)：
回忆一下，展示题目时，三个节点的线程总额有鲜明收支，题目爆发后，线程总额是增加的，更加是Lucene Merge Threads。
“多个Lucene Merge工作”与“陡增的ForceSafepoint/STW阻碍”，哪个是“因”哪个是“果”？
按照JVM日记国民党中央执行委员会调查统计局计了每一秒钟的ForceSafepoint度数，以及线程总额的变革。将两条弧线叠加在一道，获得下图：
从图中来看，犹如是ForceSafepoint渐渐增加在先，反面的线程才渐渐增加。也即是说，STW阻碍变多在先，而后多个Merge工作线程才发端渐渐积聚，就比如，一条目次上遽然增设了多个红绿灯，而后这条目次渐渐变得拥挤。
此时，发端讨教Kona JDK共青团和少先队的同窗，我把GC日记以及thread dump日记瓜分给了他，并把我暂时为止的创造都报告了他，最大的怀疑窦即是那些不平常的ForceSafepoints，我须要领会ForceSafepoints的因为。
过了一段功夫后，他恢复我：这个是arm本子的jdk。因不足arm编写翻译机救急柜，姑且没法给我供给一个debug本子的arm jdk。
遽然领会，我犯了”先入为主”的缺点，纵然一发端就认识到须要对情况举行观察。
难怪在当地X86情况中一直没辙复现。难怪网上探求ForceSafepoint时宝山空回。
接下来和存户电话聚会勾通时，获知：
一致的交易，在其余一套X86情况中，没有创造该类题目。在这套arm情况中，再有其余一个Elasticsearch集群，乞求量更低，但没有创造该类题目。情况中运用的arm jdk是从网左右载的，背地扶助的厂商未知。对于第2点提到的这套情况中的其余一个Elasticsearch集群，我更关怀的是它的GC日记中能否生存一致的局面。至于没有爆发该类题目，简单领会，由于这类题目常常是交易负载特性与情况多重成分叠加下的体例性题目。当场同窗共同翻开了这个Elasticsearch集群的GC与JVM日记，局面同在，不过ForceSafepoint的频次低于出题目的集群。
至此，题目因为明显的指向了arm情况与JDK本子。
厥后，微效劳平台TSF共青团和少先队的臧琳同窗加入，他供给了一个增添了debug消息的Kona JDK本子，纵然这个本子比平常本子慢了很多，调换此后，咱们创造题目重现的周期鲜明变长。
拿到最新的JVM日记后，臧琳同窗领会那些ForceSafepoint都与Inline Cache Buffer相关。固然，这大概是arm情况下一切JDK本子的个性题目，也大概只是是之前载入的JDK本子生存题目。
接下来，咱们将情况中的JDK本子替代成正式Release的Kona JDK。再厥后，题目一直没有复现。也即是说，替代成Kona JDK后，题目处置了。
我统计了一下运用KonaJ DK后的STW阻碍度数与阻碍功夫，创造有数目级的提高：
原JDK本子：每秒钟STW阻碍5000次～18000次，每秒钟阻碍总额据大概到达10秒～30秒。Kona JDK： 每秒钟STW阻碍在个位数，每秒钟阻碍总功夫在100～200ms之间。看来，Kona JDK比从来的题目JDK本子在本能上有了数目级的提高。
05 归纳回忆
咱们再来梳理一下所有题目的领会思绪：
1. 经过仓库领会，创造洪量的线程都在做CPU计划，但 CPU资源较闲。对于洪量Merge Threads的局面带有确定的迷惘性，但它是题目的“果”而非“因”。
2. 经过GC日记领会，创造GC频次与GC功夫都很低，但GC日记中生存洪量的STW关系日记，须要确认关系的Safepoint典型。
3. 经过VM/Safepoint日记领会，确认了Safepoint的典型为ForceSafepoint。经过各别情况与各别集群的局面比较，发端质疑JDK本子生存题目。
4. 调换Kona JDK后，ForceSafepoints频次由每秒钟5000屡次贬低到个位数，题目处置。
经过此次题目的领会，获得一个教导：题目领会前期该当刻意调查研究集群情况。固然，最大的教导是：万万不要乱载入JDK啊！