復(fù)盤線上的一次OOM和性能優(yōu)化！

上周五，發(fā)布前一周的服務(wù)器小動(dòng)蕩??

事情回顧

上周五，通過(guò)Grafana監(jiān)控，線上環(huán)境突然出現(xiàn)CPU和內(nèi)存飆升的情況：

但是看到網(wǎng)絡(luò)輸入和輸入流量都不是很高，所以網(wǎng)站被別人攻擊的概率不高，后來(lái)服務(wù)器負(fù)荷居高不下，只能保存dump文件進(jìn)行分析，并一臺(tái)一臺(tái)服務(wù)器進(jìn)行重新啟動(dòng)（還好大家周五下班了）

通過(guò)日志分析

既然服務(wù)器在某個(gè)時(shí)間點(diǎn)出現(xiàn)了高負(fù)荷，于是就先去找一開(kāi)始出現(xiàn)問(wèn)題的服務(wù)器，去找耗時(shí)的服務(wù)，例如我當(dāng)時(shí)去找數(shù)據(jù)庫(kù)耗時(shí)的服務(wù)，由于上周的日志已經(jīng)被刷掉，于是我大致描述一下：

[admin@xxx?xxxyyyy]$?grep?'15:14:'?common-dal-digest.log?|??grep?-E?'[0-9]{4,}ms'
2018-08-25?15:14:21,656?-?[(xxxxMapper,getXXXListByParams,Y,1089ms)](traceId=5da451277e14418abf5eea18fd2b61bf)

上述語(yǔ)句是查詢?cè)?5:14那一分鐘內(nèi)，在common-dal-digest.log文件中，耗時(shí)超過(guò)1000ms的SQL服務(wù)（我上周查的是耗時(shí)超過(guò)10秒的服務(wù)）。

通過(guò)traceId去查Nginx保存的訪問(wèn)日志，定位在該時(shí)間點(diǎn)內(nèi)，分發(fā)到該服務(wù)器上的用戶請(qǐng)求。還有根據(jù)該traceId，定位到整個(gè)調(diào)用流程所使用到的服務(wù)，發(fā)現(xiàn)的確十分耗時(shí)…

于是拿到了該請(qǐng)求具體信息，包括用戶的登錄手機(jī)號(hào)碼，因?yàn)檫@個(gè)時(shí)候，其它幾臺(tái)服務(wù)器也出現(xiàn)了CPU和內(nèi)存負(fù)載升高，于是根據(jù)手機(jī)號(hào)查詢了其它幾臺(tái)服務(wù)器的訪問(wèn)日志，發(fā)現(xiàn)同一個(gè)請(qǐng)求，該用戶也調(diào)用了很多次…

使用mat進(jìn)行dump文件分析

通過(guò)mat工具對(duì)dump文件進(jìn)行分析，調(diào)查是什么請(qǐng)求占用了大內(nèi)存：

觀察了該對(duì)象的引用樹(shù)，右鍵選擇【class_ reference】，查看對(duì)象列表，和觀察GC日志，定位到具體的對(duì)象信息。

通過(guò)日志以及dump文件，都指向了某個(gè)文件導(dǎo)出接口，接著在代碼中分析該接口具體調(diào)用鏈路，發(fā)現(xiàn)導(dǎo)出的數(shù)據(jù)很多，而且老代碼進(jìn)行計(jì)算的邏輯嵌套了很多for循環(huán)，計(jì)算效率低。

查詢了該用戶在這個(gè)接口的所調(diào)用的數(shù)據(jù)量，需要查詢?nèi)齻€(gè)表，然后for循環(huán)中大概會(huì)計(jì)算個(gè)100w+次，導(dǎo)致阻塞了其它請(qǐng)求，線上的服務(wù)器CPU和內(nèi)存使用情況一直飆升。

代碼進(jìn)行性能優(yōu)化

在看到該業(yè)務(wù)在git提交記錄是我上一年實(shí)習(xí)期寫的時(shí)候，我的內(nèi)心是崩潰的，當(dāng)時(shí)對(duì)業(yè)務(wù)不熟悉，直接循環(huán)調(diào)用了老代碼，而且也沒(méi)有測(cè)試過(guò)這么大的數(shù)據(jù)量，所以GG了。

然后我就開(kāi)始做代碼性能優(yōu)化，首先仔細(xì)梳理了一下整個(gè)業(yè)務(wù)流程，通過(guò)增加SQL查詢條件，減少數(shù)據(jù)庫(kù)IO和查詢數(shù)據(jù)量，優(yōu)化判斷條件，減少for嵌套、循環(huán)次數(shù)和計(jì)算量。

通過(guò)jvisualVM進(jìn)行對(duì)比

對(duì)比新老代碼所占用的CPU和內(nèi)存狀態(tài)

優(yōu)化前：

優(yōu)化后：

通過(guò)上述優(yōu)化之后，計(jì)算1w條數(shù)據(jù)量進(jìn)行導(dǎo)出，在老代碼需要48s，新代碼也要8s，不過(guò)這是大數(shù)據(jù)量的情況下，實(shí)際用戶的數(shù)據(jù)沒(méi)有這么多，所以基本上滿足了線上99%的用戶使用。

當(dāng)然，由于這些數(shù)據(jù)是本地開(kāi)發(fā)環(huán)境新增加的，與出現(xiàn)OOM問(wèn)題的用戶數(shù)據(jù)量還有些差別，但通過(guò)優(yōu)化后的代碼，已經(jīng)在數(shù)據(jù)庫(kù)查詢的時(shí)候就過(guò)濾掉很多無(wú)效的數(shù)據(jù)，在for循環(huán)計(jì)算前也加了過(guò)濾條件，所以真正計(jì)算起來(lái)起來(lái)就降低了很多計(jì)算量。

恩，自己優(yōu)化好了，還要等測(cè)試爸爸們測(cè)試后才敢上線，這次要瘋狂造數(shù)據(jù)

開(kāi)發(fā)注意點(diǎn)

在開(kāi)發(fā)一開(kāi)始的時(shí)候，都沒(méi)有考慮到性能問(wèn)題，想著滿足需求就完成任務(wù)，但數(shù)據(jù)量一大起來(lái)，就有可能出現(xiàn)這些OOM問(wèn)題，所以以后開(kāi)發(fā)時(shí)，需要考慮一下幾點(diǎn)：

• 梳理設(shè)計(jì)流程
• 考慮是否有性能問(wèn)題
• 與產(chǎn)品經(jīng)理商量控制查詢條件，減少查詢的范圍
• 與數(shù)據(jù)庫(kù)交互時(shí)，減少無(wú)效的查詢，合并查詢和合并更新操作
• 減少for循環(huán)，尤其注意for循環(huán)嵌套問(wèn)題！
• 調(diào)用老代碼要看注意=-=

吐槽

果然每次看之前寫的代碼，都有種要si要si的感覺(jué).

往期推薦

不要再用main方法測(cè)試代碼性能了，用這款JDK自帶工具

Socket粘包問(wèn)題的3種解決方案，最后一種最完美！

MySQL為Null會(huì)導(dǎo)致5個(gè)問(wèn)題，個(gè)個(gè)致命！