一.what‘s going on in Java Application
當系統卡頓，應用莫名被殺掉，我們應該怎么排查？在我已知的系統掛掉的情況，只經歷過兩種：1.內存申請不了（OOM）；2.CPU占用過高
使用top命令即可以觀察linux的進程信息，以及CPU占用信息，拿到了進程號就可以進一步了解進程信息。
netstat -apn | grep 35011
即可觀察java應用所監聽的端口。
如果機子上配置了Java環境，則使用jps命令即可看到Java進程號。
通常我最常用是
jps -ml
可顯示給主函數傳入的參數，並顯示主類的完整包名。
可以查詢啟動Java進程時候jvm的參數，使用
jps -v
可以看到一些收集器的配置（以上是使用CMS），Java堆的內存配置，等等。注意里面有一個參數，HeapDumpOnOutofMemmoryError，這個參數說明JVM在檢測到內存溢出的時候會輸出一個內存快照，並輸出到后面這個dumpPath中。
內存溢出有兩種情況，一種是到達JVM設置的最大內存，而這個時候並沒有到達Linux系統內存瓶頸，這個時候應該是不會把Java殺掉（猜測）；另一種是造成了Linux系統內存申請問題，則Linux會殺掉這個異常進程（Linux Kernel OOM(Out of memory killer)）。
如果想從linux層面查看進程，則進入文件夾;Linux的進程是以文件形式記錄的，也就是fd的概念。
/proc/{pid}/status
linux日志文件說明 (抄過來的) /var/log/message 系統啟動后的信息和錯誤日志，是Red Hat Linux中最常用的日志之一 /var/log/secure 安全相關的日志信息 /var/log/maillog 郵件相關的日志信息 /var/log/cron 定時任務相關的日志信息 /var/log/spooler UUCP和news設備相關的日志信息 /var/log/boot.log 守護進程啟動和停止相關的日志消息 /var/log/wtmp 該日志文件永久記錄每個用戶登錄、注銷及系統的啟動、停機的事件
有一次查詢OOM掛掉的應用信息，在阿里雲監控里內存下來的那個時間點，去查message，看到了Linux的OOM kill的日志。
二.Memmory or CPU
在市面上看到的Java應用，無論是處理什么業務的，最常見的就是對這兩種資源的支配。計算密集型，考慮空間換時間；文檔型、內存型的，考慮優化業務方法或者考慮多台機器。根據以上的方法，我們可以對Java進程的一些指標進行監控，而我們如果需要進一步知道卡頓的原因，則我們可以使用jdk自帶的工具進行查詢。
內存這個主題可以分為很多場景：堆內存不足（業務需求增長、代碼中申請內存不合理導致頻繁Full GC、一次申請內存超過JVM設置、內存溢出）、常量池內存不足、Linux內存不足、爆棧 等等。但是大多數情況下，我們都是可以預料到的（大多數都是代碼的問題）。如果你有一個業務，會加載大量的文檔，那你肯定一開始就知道需要准備可伸縮型架構了（只要加機器就能解決線上問題的架構，也就是便於橫向擴展）。所以，在內存這個主題上，我們只需要關注一些不是立即發生、在系統運行中逐漸拖垮系統的問題排查，比如，內存溢出。
在Java中，內存溢出指的是使用過的並且未來不再使用的內存沒有被GC正常回收的情況。舉個例子，你在系統中使用了全局的Map記錄一些業務以及數據對應的關系，而key值是業務產生時候的標志（每次業務都會不一樣），value值是每次業務的對應數據；如果在業務完成之后沒有remove，則在系統運行的過程中，這個Map是會不斷增大的，最終這些無用的內存會導致OOM。（當然，一個正常的程序員是不會這么寫的）
我們在內存溢出的時候可能做得更加隱秘，所以需要使用jdk的工具幫助我們發現這些問題。
jmap -histo {pid} | head
這個是正常的內存快照，如果是不正常的，則排在前幾的有可能就是你寫的那個數據結構。再通過一些手段定位出是代碼中的哪行。這樣我們排查內存溢出就會簡單一些了。
[ctk@172 ~]$ jmap -heap 35011 Attaching to process ID 35011, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.181-b13 using parallel threads in the new generation. using thread-local object allocation. Concurrent Mark-Sweep GC Heap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 1073741824 (1024.0MB) NewSize = 87228416 (83.1875MB) MaxNewSize = 87228416 (83.1875MB) OldSize = 986513408 (940.8125MB) NewRatio = 2 SurvivorRatio = 8 MetaspaceSize = 21807104 (20.796875MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize = 17592186044415 MB G1HeapRegionSize = 0 (0.0MB) Heap Usage: New Generation (Eden + 1 Survivor Space): capacity = 78512128 (74.875MB) used = 39575536 (37.74217224121094MB) free = 38936592 (37.13282775878906MB) 50.40690783467237% used Eden Space: capacity = 69795840 (66.5625MB) used = 39518256 (37.68754577636719MB) free = 30277584 (28.874954223632812MB) 56.6197870818662% used From Space: capacity = 8716288 (8.3125MB) used = 57280 (0.05462646484375MB) free = 8659008 (8.25787353515625MB) 0.6571604793233082% used To Space: capacity = 8716288 (8.3125MB) used = 0 (0.0MB) free = 8716288 (8.3125MB) 0.0% used concurrent mark-sweep generation: capacity = 986513408 (940.8125MB) used = 115758360 (110.3957748413086MB) free = 870755048 (830.4167251586914MB) 11.734088869068874% used 25248 interned Strings occupying 3380280 bytes.
使用-heap查看堆信息，這樣就能整體看看內存的情況。
另一種情況，是收集器選型不合理導致的gc卡頓，這樣需要去觀察gc的狀態，用到了jdk的另一種工具：jstat
[ctk@172 ~]$ jstat -gc 35011 S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 8512.0 8512.0 55.9 0.0 68160.0 32072.9 963392.0 113045.3 79036.0 72618.0 12220.0 10128.0 44 2.041 6 0.129 2.170
帶c的意思是capacity（容量）的意思，帶u的是used（已使用）的意思。s0，s1這些都是書上的概念，年輕代，老年代等等。M是method，方法區的意思。一般看的是YGC，YGCT，就是young gc次數，young gc time；FGC，FGCT，full gc次數，full gc time等參數。如果full gc的時間過長，young gc次數過於頻繁，則考慮去優化代碼。
[ctk@172 ~]$ jstat -gcutil 35011 100 S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.66 0.00 62.44 11.73 91.88 82.88 44 2.041 6 0.129 2.170 0.66 0.00 62.44 11.73 91.88 82.88 44 2.041 6 0.129 2.170 0.66 0.00 62.44 11.73 91.88 82.88 44 2.041 6 0.129 2.170 0.66 0.00 62.44 11.73 91.88 82.88 44 2.041 6 0.129 2.170
后邊帶個100指100ms輸出一次。
至今還沒碰到gc來不及而內存爆炸的情況，如果出現大體都是代碼寫得不好。
另一個topic，就是CPU占用過高的問題。CPU占用過高的情況很容易聯想就是死循環，線程一直Runnable而且不退出。很多情況下都是BUG，沒有什么業務會讓Java進程使用那么高的占用率。我遇到過三次，情況都不一樣，都歸於BUG。
第一個，是在一個2c的系統里面，使用了全局jdk1.7的Map，並且是HashMap。在resize和put的過程中，鏈表成了環，所以在系統開的Thread中，卡在ContainsKey這個方法中，導致CPU占用過高掛掉，這個問題很隱蔽，並且是幾率型發生的（誰也不能保證成環，也不能保證你計算到那個環上）。我們最初是使用top命令觀察一段時間，發現CPU莫名的高，但是內存占用卻不高，而且不是業務旺季。這個時候要采用jdk提供的另一種工具：jstack
[ctk@172 ~]$ jstack 35011 | grep RUNNABLE -A 5 java.lang.Thread.State: RUNNABLE "elasticsearch[BeEZ6i3][trigger_engine_scheduler][T#1]" #50 daemon prio=5 os_prio=0 tid=0x00007faaf869f000 nid=0x88f9 waiting on condition [0x00007faaba846000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c881d468> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) -- java.lang.Thread.State: RUNNABLE "elasticsearch[keepAlive/6.7.2]" #10 prio=5 os_prio=0 tid=0x00007faaf9fa8000 nid=0x88f8 waiting on condition [0x00007faabad47000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c571a008> (a java.util.concurrent.CountDownLatch$Sync) -- java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000000c9ce5940> (a sun.nio.ch.Util$3) -- java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000000c9ce5d90> (a sun.nio.ch.Util$3) -- java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000000c9c57a08> (a sun.nio.ch.Util$3) -- java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000000c9c58398> (a sun.nio.ch.Util$3) -- java.lang.Thread.State: RUNNABLE at java.io.FileInputStream.readBytes(Native Method) at java.io.FileInputStream.read(FileInputStream.java:233) at org.elasticsearch.xpack.ml.process.logging.CppLogMessageHandler.tailStream(CppLogMessageHandler.java:105) at org.elasticsearch.xpack.ml.process.NativeController.lambda$tailLogsInThread$0(NativeController.java:70) at org.elasticsearch.xpack.ml.process.NativeController$$Lambda$1840/1525943877.run(Unknown Source) -- java.lang.Thread.State: RUNNABLE at java.lang.UNIXProcess.waitForProcessExit(Native Method) at java.lang.UNIXProcess.lambda$initStreams$3(UNIXProcess.java:289) at java.lang.UNIXProcess$$Lambda$135/1183231938.run(Unknown Source) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) -- java.lang.Thread.State: RUNNABLE "C1 CompilerThread1" #7 daemon prio=9 os_prio=0 tid=0x00007faaf80fa000 nid=0x88ce waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #6 daemon prio=9 os_prio=0 tid=0x00007faaf80f8000 nid=0x88cd waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #5 daemon prio=9 os_prio=0 tid=0x00007faaf80f5800 nid=0x88cc runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Surrogate Locker Thread (Concurrent GC)" #4 daemon prio=9 os_prio=0 tid=0x00007faaf80f4800 nid=0x88cb waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007faaf80c1800 nid=0x88ca in Object.wait() [0x00007faad3ffe000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c5888f08> (a java.lang.ref.ReferenceQueue$Lock)
我們先是定位RUNNABLE的線程，發現有好幾個線程都是卡在containsKey這個方法。這個方法就是去hash一個key，並遍歷鏈表看看這個key是否存在。這里有一個循環，如果循環不結束，則線程是一直RUNNABLE的，而且即使客戶端DISCONNECT，也不能保證這個Thread停止。我們是web服務，斷開連接，但是后台線程依然是沒有結束。
然后回憶起並發編程那本書里提到的，並發下詭異的HashMap，遂猜測成環。因為使用的是static HashMap，所以建議修改為ConcurrentHashMap，觀察一段時間之后，問題修復。
第二個是在進行阿里雲vpc服務遷移的時候，發布生產的時候，莫名其妙服務不打錯誤日志，而應用起不來，屢試不爽。並且在啟動的很久之后，報了Socket TimeOut之類的錯誤。然后啟動的時候使用jstack查狀態，發現主線程main卡在數據庫連接上，一直是RUNNABLE的情況，最終在啟動很久之后報出TIMEOUT之類的錯誤。（沒有現場日志了）所以推測是服務器與數據庫的鏈接配置（安全組，權限，用戶）是否正常，最終是安全組的配置問題。
第三個問題非常詭異，消息中心采用ActiveMQ，業務方使用ActiveMQ Client進行使用。而消息中心閃斷之后，理應觸發重連機制，但是在拋出一個異常JMS 什么Support Exception之后，CPU變得異常的高。而在拋出這個異常的時候，拋出了一個NoClassDef異常，這個異常大概率是jar沖突。這個問題沒有詳細排查，猜測是ActiveMQ在處理這個異常的時候，如果找不到有可能仍然不斷發起重連，一直新建重連線程導致的。由於是老系統，所以沒有詳細查了，根本原因還是依賴太過混亂。
dump內存。
jmap -dump:format=b,file=dump.hprof {pid}
使用MAT進行內存分析。
新鮮案例，幽靈一般的內存泄露。由於內存中的ArrayList占據老年代大量內存，觸發的fullgc不能把它gc掉導致頻繁的fullgc，進而CPU 100%，接口變慢。
還沒找到原因。
MemoryAnalyzer.exe-vmargs -Xmx4g
打開MAT時候指定最大內存。
三.In Conclusion
如果除去以上兩種，系統響應慢還有一個，就是Linux IO問題。這個不常遇到，但是一個中間件的熟人在做RocketMQ搭建的時候，我體驗到了這種差別。（首先IO同步異步會有TPS的差別，cache和零拷貝又有區別）我並不精通，所以不再總結。
日常的業務系統，如果不是業務正常引起的，最主要排查的是內存溢出以及不正常的Runnable引起的CPU過高。搞定這兩個，就可以了。