前幾天告警群里報(bào)出一個(gè)go服務(wù)grpc接口出現(xiàn)很多超時(shí)現(xiàn)象，排查發(fā)現(xiàn)是服務(wù)有內(nèi)存泄露與cpu占用高的問題，在這里將排查的過程記錄一下，給大家提供排查問題的方向與思路，同時(shí)借鑒教訓(xùn)，優(yōu)化自己服務(wù)代碼。

發(fā)現(xiàn)超時(shí)現(xiàn)象后，登錄機(jī)器看了下top，該服務(wù)總共有兩臺(tái)機(jī)器，發(fā)現(xiàn)02機(jī)器的cpu與內(nèi)存占用很高（如下圖第一個(gè)進(jìn)程），而01機(jī)器都很低。

正常情況下不會(huì)有這么高的資源占用，可能是服務(wù)有資源泄露的問題，資源一致得不到釋放。

首先做的，是重啟服務(wù)，優(yōu)先解決問題，資源泄露的問題可以通過重啟來快速解決，重啟后接口超時(shí)現(xiàn)象不再出現(xiàn)，接口耗時(shí)恢復(fù)正常。

重啟后，開始排查問題，超時(shí)的服務(wù)是B服務(wù)，上游有A服務(wù)調(diào)用B服務(wù)，從A服務(wù)中找了幾個(gè)超時(shí)的請(qǐng)求，根據(jù)opentracing生成的tracer_id查詢?nèi)罩荆l(fā)現(xiàn)A服務(wù)調(diào)用B服務(wù)超時(shí)5s就返回錯(cuò)誤了，B服務(wù)收到了A服務(wù)的請(qǐng)求，發(fā)現(xiàn)有兩種情況，一種是B立即收到了A的請(qǐng)求，但是處理了400+秒才返回；另一種是A發(fā)出請(qǐng)求400+秒后，B才開始處理請(qǐng)求。

另外發(fā)現(xiàn)grpc請(qǐng)求全部打到一臺(tái)機(jī)器上，另一臺(tái)機(jī)器沒什么量。

然后去看了下歷史cpu、內(nèi)存曲線，發(fā)現(xiàn)cpu在15分鐘內(nèi)上升至很高，同時(shí)內(nèi)存占用很高的現(xiàn)象。

拉長了內(nèi)存統(tǒng)計(jì)時(shí)間，發(fā)現(xiàn)A服務(wù)的內(nèi)存在緩慢增長，肯定是有內(nèi)存泄露的問題：

總結(jié)下觀察到的問題：

• 請(qǐng)求為什么全部打到一臺(tái)機(jī)器上，兩臺(tái)機(jī)器的前面是有slb的，難道slb沒有發(fā)揮作用嗎？
• cpu占用在15分鐘快速增長的原因是什么？
• 請(qǐng)求處理時(shí)間慢的原因是什么？
• 為什么會(huì)有內(nèi)存泄露現(xiàn)象出現(xiàn)？

Q1 slb沒有負(fù)載均衡

原因

針對(duì)Q1，特意去查了下slb的配置，由于slb是根據(jù)權(quán)重輪詢的，可能權(quán)重配置錯(cuò)誤導(dǎo)致的請(qǐng)求分配不均，但是看了配置，slb的配置并沒有問題，兩臺(tái)后端服務(wù)器的權(quán)重相同。

然后去查了下，發(fā)現(xiàn)我們的slb是4層（tcp/udp層）的負(fù)載均衡，4層的slb是針對(duì)連接做負(fù)載均衡的，而不是針對(duì)請(qǐng)求，當(dāng)連接的客戶端很少時(shí)，負(fù)載也可能不均衡，4層的負(fù)載均衡是客戶端和服務(wù)器tcp直連。

然后去兩臺(tái)機(jī)器上netstat看了下，發(fā)現(xiàn)01機(jī)器沒有A服務(wù)的連接，02機(jī)器有A服務(wù)的連接。同時(shí)grpc維持的是長連接并且復(fù)用連接，對(duì)于新請(qǐng)求不會(huì)新建連接，這樣在第一次經(jīng)過slb的負(fù)載均衡創(chuàng)建連接后，grpc的請(qǐng)求會(huì)復(fù)用這個(gè)連接，請(qǐng)求會(huì)全部打到連接的機(jī)器上。

如何解決？

知道原因了，那么如何解決呢？可以通過etcd與grpc兩者結(jié)合來實(shí)現(xiàn)服務(wù)注冊與服務(wù)發(fā)現(xiàn)，grpc客戶端根據(jù)所有server的ip來實(shí)現(xiàn)負(fù)載均衡。

Q2 cpu快速增長

原因

對(duì)于Q2，由于當(dāng)時(shí)服務(wù)沒有設(shè)置pprof，無法看到運(yùn)行的狀況……后面加了pprof，又不能馬上復(fù)現(xiàn)，所以暫時(shí)是通過看代碼的方式來猜測哪些地方可能出了問題- -

想到之前的請(qǐng)求處理了400+秒，并且當(dāng)時(shí)內(nèi)存占用很高，代碼中又有worker類的任務(wù)，每秒從數(shù)據(jù)庫中取出數(shù)據(jù)，對(duì)每條數(shù)據(jù)啟動(dòng)一個(gè)goroutine處理。

偽代碼如下：

for {
	datas := Mysql.GetDatas()
	for _, v := range datas {
		cur := v
		go func() {
			handle(cur)
		}
	}
	time.Sleep(time.Second)
}

正常情況下，這是沒問題的，但是當(dāng)時(shí)機(jī)器的內(nèi)存占用接近100%，那么goroutine的處理時(shí)間肯定變長，如果處理時(shí)間超過1秒甚至遠(yuǎn)超一秒，那么這個(gè)goroutine還沒處理完，worker又新起了一個(gè)goroutine，goroutine的數(shù)量沒有控制，多了以后又占用更多資源，舊的goroutine處理時(shí)間更長，worker還是每秒啟動(dòng)一個(gè)新的goroutine……后面就產(chǎn)生了goroutine泄露，這可能是導(dǎo)致cpu增長的主要原因。

所以初步猜測是內(nèi)存泄露問題，導(dǎo)致內(nèi)存占用很高，然后導(dǎo)致goroutine處理時(shí)間過長，又導(dǎo)致goroutine泄露，goroutine進(jìn)一步導(dǎo)致cpu、內(nèi)存增長。

后來在線上加了pprof，但是內(nèi)存泄露比較緩慢，需要等一段時(shí)間才能捕獲，到時(shí)候在這里補(bǔ)充。

如何解決？

對(duì)于goroutine泄露的解決，自然是控制goroutine的數(shù)量，我把偽代碼改成了如下來控制goroutine（判斷超過限制數(shù)量就sleep）：

int32 runningG = 0
const maxRunningG = 200
for {
	if atomic.LoadInt32(&runningG) > maxRunningG {
		time.Sleep(time.Seconds * 3)
		continue
	}
	datas := Mysql.GetDatas()
	for _, v := range datas {
		cur := v
		atomic.AddInt32(&runningG, 1)
		go func() {
			handle(cur)
			atomic.AddInt32(&runningG, -1)
		}
	}
	time.Sleep(time.Second)
}

Q3 請(qǐng)求處理緩慢

原因

處理請(qǐng)求緩慢的原因可能是Q2 goroutine泄露問題導(dǎo)致的cpu占用過高，請(qǐng)求處理不過來了。

如何解決？

參考Q2解決方案

Q4 內(nèi)存泄露問題

原因1

同樣也是直接從代碼的角度排查，借鑒了網(wǎng)上一些人的內(nèi)存泄露經(jīng)驗(yàn)，發(fā)現(xiàn)一個(gè)方法中對(duì)于http請(qǐng)求的處理方式可能有問題。

對(duì)于每個(gè)http請(qǐng)求，該方法每次都會(huì)新建一個(gè)http.Client與transport, 偽代碼如下。

...
tr := &http.Transport{
   TLSClientConfig: &tls.Config{
      ... // 證書相關(guān)
   },
}
client := &http.Client{Transport: tr}
response, err := client.Post(url, contentType, body)
if err != nil {
   return
}
responseByte, err := ioutil.ReadAll(response.Body)
if err != nil {
   return
}
...

而通過http.Client與transport的注釋我們可以看出這兩個(gè)是可以復(fù)用的。

http.Client:

// The Client's Transport typically has internal state (cached TCP
// connections), so Clients should be reused instead of created as
// needed. Clients are safe for concurrent use by multiple goroutines.
//

http.Transport:

// Transports should be reused instead of created as needed.
// Transports are safe for concurrent use by multiple goroutines.

且該方法對(duì)于http.Response.Body沒有調(diào)用**Close()**方法，這可能導(dǎo)致潛在的資源泄露。

如何解決？

創(chuàng)建全局的http Client和Transport并且設(shè)置好超時(shí)時(shí)間等參數(shù)，復(fù)用這個(gè)client。http請(qǐng)求返回的response需要調(diào)用http.Response.Body.Close()釋放連接使其可以被其他協(xié)程復(fù)用。

原因2

同時(shí)發(fā)現(xiàn)對(duì)于mysql查詢結(jié)果的處理，也可能有些問題，偽代碼如下：

rows, err := db.Query(sql, case)
if err != nil {
	return
}
for rows.Next() {
	if err = rows.Scan(...); err != nil{
		return
	}
	...
}

對(duì)于sql.Query的結(jié)果rows，如果沒有rows.Close()，但是rows.Scan()讀取了所有的數(shù)據(jù)，那么rows的資源會(huì)自動(dòng)得到釋放；

但是如果Scan發(fā)生錯(cuò)誤，rows沒有讀取完，又沒有rows.Close()，就可能導(dǎo)致潛在的內(nèi)存泄露。

如何解決？

每次都調(diào)用rows.Close()方法來釋放資源。

rows, err := db.Query(sql, case)
if err != nil {
	return
}
defer rows.Close() //
for rows.Next() {
	if err = rows.Scan(...); err != nil{
		return
	}
	...
}

其他原因

通過pprof正在分析中…… 待補(bǔ)充。

總結(jié)

以上為個(gè)人經(jīng)驗(yàn)，希望能給大家一個(gè)參考，也希望大家多多支持腳本之家。

最新評(píng)論