運維：你們 JAVA 服務怎么又又又又出問題了！內(nèi)存降不下來！
在上次在運維老哥友好的和我溝通之后，還消停沒幾天，今天又來找（問候）我了……
運維：這個服務也是你們的吧，你看這個 JAVA 進程，內(nèi)存占用都快 3 個 G 了，這機器才 4G，你們堆才配置 2G，都要告警了！這次是真的內(nèi)存泄露了吧，不是我無知了吧！
又來搞事情……這大哥是對我有意見嗎？有了上次的經(jīng)驗，這回更自信了。還是按照慣例，先懟回去
我：“不可能，我們服務非常穩(wěn)定，不會有這種問題！”
運維：你這哪來的自信和勇氣？梁靜茹給的嗎？你先回去查查再裝
看來大哥這回是有備而來啊，難道真是出問題了？有點慌了……
不過還是不能慫，先敷衍下運維老哥，找個借口回去先偷摸查查監(jiān)控看看
我：行，我待會看看，我先去跟人開個會啊……
分析監(jiān)控數(shù)據(jù)
這個服務的堆內(nèi)存配置的是 2G，歷史內(nèi)存也確實達到過 2G，雖然現(xiàn)在 used 才幾百兆……看起來也沒啥問題
再加上一些 VM 自己的開銷，一共占用 2 個多 G……好像也說的過去
然后我又找到了運維大哥，（友好的）溝通一下……
我：和上次一樣啊，沒什么區(qū)別，上次都解釋過那個內(nèi)存管理的機制了，你咋還說我們有問題？
運維：你看你們這個服務，配置的是 CMS+ParNew 垃圾回收器吧，上次是你說的這個回收器組合下會釋放內(nèi)存給操作系統(tǒng)吧？那怎么還占用 2G，釋放到哪去了？
我：雖然上回測試結果是會釋放，但還有一些其他的說法，說是空閑時會增量釋放，而且釋放成本這么高，不釋放又怎么樣？
運維：你這話不是打自己臉么？上回說能釋放，現(xiàn)在沒釋放你也說正常，你是不是覺得我傻？
運維大哥好像看出了我是在狡辯……
不釋放也正常啊，釋放成本這么高，釋放后還得重新申請，重新組織內(nèi)存結構balabalabala……
這話說的我自己都沒底氣……畢竟上次才測試過 CMS+ParNew 確實會釋放，只是時間問題
運維：你繼續(xù)狡辯，這服務的內(nèi)存照這個趨勢，估計要不要明天就得 OOM，然后系統(tǒng)再給你來個 OOM Killer 的絕殺，你可就開心了！
我：沒問題的，這個內(nèi)存正常，自己的服務，我還能不了解嘛
此時我已經(jīng)有點不安了，大哥說的有道理啊，萬一 OOM Killer了，可不完蛋了！
我：我晚點有空再仔細看看，應該沒啥問題，你先忙你的，放心！
上服務器查實時指標
打發(fā)走了運維老哥之后，我仔細思考了一會。這內(nèi)存的數(shù)據(jù)好像確實不太正常，這個服務屬于那種后端應用，雖然業(yè)務復雜，但只是給業(yè)務大佬們用。不過這個內(nèi)存占用確實有點說不過去啊，到底內(nèi)存跑哪去了……
還是數(shù)據(jù)說話吧，上主機上找找看有沒有什么線索
內(nèi)存 - ok
CPU 利用率 - ok
CPU 負載 - ok
也沒什么異常，CPU 利用率和負載啥的都很低……到底問題出在哪？
這么一點點的看指標太費勁了，還是拿 Arthas 看吧，JVM 相關的指標它基本都顯示，比較全：
[arthas@20727]$ dashboard
Memory used total max usage GC
heap 498M 1963M 1963M 25.1% gc.ps_scavenge.count 3
ps_eden_space 98M 512M 512M 19.5% gc.ps_scavenge.time(ms) 44
ps_survivor_space 0K 87040K 87040K 0.00% gc.ps_marksweep.count 1
ps_old_gen 39M 1365M 1365M 2.88% gc.ps_marksweep.time(ms) 87
nonheap 32M 180M -1 17.7%
code_cache 10M 50M 240M 20%
metaspace 20M 128M -1 15.6%
compressed_class_space 2M 2M 1024M 0.25%
復制代碼看起來JVM 級別的內(nèi)存也沒啥問題，再看看線程呢：
[arthas@20727]$ thread
Threads Total: 9831, NEW: 0, RUNNABLE: 8, BLOCKED: 0, WAITING: 9789, TIMED_WAITING: 2, TERMINATED: 0, Internal threads
: 17
復制代碼臥槽，這什么玩意！快 1w 個線程！還基本上都是 WAITING！
趕緊看看這些 WAITING 的線程都是些啥：
[arthas@20727]$ thread --state WAITING
ID NAME GROUP PRIORITY STATE %CPU DELTA_TIM TIME INTERRUPT DAEMON
# 此處省略 9000+ 行……
9822 pool-9813-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9823 pool-9814-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9824 pool-9815-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9825 pool-9816-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9826 pool-9817-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9827 pool-9818-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9828 pool-9819-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9829 pool-9820-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9830 pool-9821-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9831 pool-9822-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9832 pool-9823-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9833 pool-9824-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9834 pool-9825-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9835 pool-9826-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9836 pool-9827-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9837 pool-9828-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9838 pool-9829-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9839 pool-9830-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
9840 pool-9831-thread-1 main 5 WAITING 0.0 0.000 0:0.000 false false
復制代碼看到這個線程名，我也大概明白了，一定是哪個小天才在代碼里下毒。
從線程名稱來看，肯定是線程池里的線程嘛，而且是默認的線程名生成規(guī)則。線程池里的線程都是通過 ThreadFactory 來創(chuàng)建的，而默認的 ThreadFactory 生成規(guī)則就是這樣：
DefaultThreadFactory() {
SecurityManager s = System.getSecurityManager();
group = (s != null) ? s.getThreadGroup() :
Thread.currentThread().getThreadGroup();
// 前綴，每一個新的 ThreadFactory 都有一個新的前綴
// 每一個線程池，都只有一個 ThreadFactory
namePrefix = "pool-" +
poolNumber.getAndIncrement() +
"-thread-";
}
public Thread newThread(Runnable r) {
// 每個線程都會使用 factory的前綴，然后加上自增的線程數(shù)
Thread t = new Thread(group, r,
namePrefix + threadNumber.getAndIncrement(),
0);
if (t.isDaemon())
t.setDaemon(false);
if (t.getPriority() != Thread.NORM_PRIORITY)
t.setPriority(Thread.NORM_PRIORITY);
return t;
}
復制代碼所以這個問題，肯定是哪個小天才，在代碼里每次都新建線程池，然后還不 shutdown 導致的！隨便找個線程，看看它的 stack：
"pool-1-thread-1" Id=10 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6ba7592
at sun.misc.Unsafe.park(Native Method)
- waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6ba7592
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
復制代碼實錘了，就是每次 new 線程池不 shutdown……現(xiàn)在只需要找到創(chuàng)建線程池的地方，再翻翻提交記錄，就可以知道是哪個小天才了……
但代碼這么多，想找到這個新建線程池的地方還是有點麻煩的，搜代碼可不太方便。這里還是用 Arthas 來看看，stack 一看就知道
不過如果這里直接 stack ThreadPoolExecutor#execute 方法的話，干擾信息可能太多了，畢竟調(diào)用 execute 的地方太多，不好抓到重點
所以還是 stack 線程池初始化的方法比較好：
[arthas@20727]$ stack java.util.concurrent.ThreadPoolExecutor <init>
Affect(class count: 0 , method count: 0) cost in 4 ms, listenerId: 5
No class or method is affected, try:
1. Execute `sm CLASS_NAME METHOD_NAME` to make sure the method you are tracing actually exists (it might be in your parent class).
2. Execute `options unsafe true`, if you want to enhance the classes under the `java.*` package.
3. Execute `reset CLASS_NAME` and try again, your method body might be too large.
4. Check arthas log: /home/jiangxin/logs/arthas/arthas.log
5. Visit https://github.com/alibaba/arthas/issues/47 for more details.
復制代碼這……是不支持嗎？
Arthas 的增強策略是比較保守的，部分系統(tǒng)級別的類它不做增強，java.* 包下的類默認是不增強的，需要手動開啟才行：
[arthas@20727]$ options unsafe true
NAME BEFORE-VALUE AFTER-VALUE
-----------------------------------
unsafe false true
復制代碼再次執(zhí)行 stack 之后，可以用了。過了兩分鐘之后，終于有一次調(diào)用：
ts=2021-06-12 12:04:03;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@4e0e2f2a
@java.util.concurrent.ThreadPoolExecutor.<init>()
at java.util.concurrent.Executors.newFixedThreadPool(Executors.java:89)
at XXXService.sendSms(XXXService.java:782)
//...
復制代碼終于找到了這個騷操作代碼……它是這么寫的：
ExecutorService executorService = Executors.newFixedThreadPool(8);
executorService.submit(smsTask);
//...
復制代碼和我猜測的一樣，果然是每次 new，然后還不 shutdown。
這也能和上面的情況對上了，多出的內(nèi)存占用是因為這小一萬個線程……而且這些線程池沒有任務需要執(zhí)行的話，線程肯定是 WAITING 狀態(tài)，也不會占用 CPU 的利用率，負載有不會有影響。不仔細還真看不出問題 ，還是得結合各種指標來看，綜合分析。
解決這個問題倒簡單，讓寫這個屎代碼的人去改了，然后拉出去祭天。
可是運維大哥那邊……已經(jīng)裝出去了，這下臉可是丟完了。上次好不容易掙回來的面子，這次啥都沒了
給運維的交代
我：服務確實有點問題，我們發(fā)個緊急修復版本，晚上上線就能解決了
運維：你不是說沒問題么？自信哪去了
我：這不是沒吃早飯，餓的頭發(fā)昏，腦子不夠清醒……沒看出來問題，我的鍋我的鍋
運維：肯定是你們的屎山代碼導致的，沒事也搞搞 code review ，查查代碼，以后少出這種低級問題，不然我一天到晚處理你們這些破事不得煩死了
沒想到這運維還喘起來了，給點面子就要上天……不過誰讓我理虧呢，只能應下
我：對對對，我們以后一定多搞 code review，加強代碼審查，避免這種屎代碼再提交上去，影響生產(chǎn)。不給大佬添麻煩
作者：空無
鏈接：https://juejin.cn/post/6973808359614971918
來源：掘金
著作權歸作者所有。商業(yè)轉載請聯(lián)系作者獲得授權，非商業(yè)轉載請注明出處。