前幾天告警群里報(bào)出一個(gè)go服務(wù)grpc接口出現(xiàn)很多超時(shí)現(xiàn)象，排查發(fā)現(xiàn)是服務(wù)有內(nèi)存泄露與cpu占用高的問(wèn)題，在這里將排查的過(guò)程記錄一下，給大家提供排查問(wèn)題的方向與思路，同時(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èn)題，資源一致得不到釋放。

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

重啟后，開(kāi)始排查問(wèn)題，超時(shí)的服務(wù)是B服務(wù)，上游有A服務(wù)調(diào)用B服務(wù)，從A服務(wù)中找了幾個(gè)超時(shí)的請(qǐng)求，根據(jù)opentracing生成的tracer_id查詢(xún)?nèi)罩?，發(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才開(kāi)始處理請(qǐng)求。

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

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

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

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

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

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

原因

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

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

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

如何解決？

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

Q2 cpu快速增長(zhǎng)

原因

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

想到之前的請(qǐng)求處理了400+秒，并且當(dāng)時(shí)內(nèi)存占用很高，代碼中又有worker類(lèi)的任務(wù)，每秒從數(shù)據(jù)庫(kù)中取出數(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)
}

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

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

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

如何解決？

對(duì)于goroutine泄露的解決，自然是控制goroutine的數(shù)量，我把偽代碼改成了如下來(lái)控制goroutine（判斷超過(guò)限制數(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泄露問(wèn)題導(dǎo)致的cpu占用過(guò)高，請(qǐng)求處理不過(guò)來(lái)了。

如何解決？

參考Q2解決方案

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

原因1

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

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

...
tr := &http.Transport{
   TLSClientConfig: &tls.Config{
      ... // 證書(shū)相關(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
}
...

而通過(guò)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沒(méi)有調(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查詢(xún)結(jié)果的處理，也可能有些問(wèn)題，偽代碼如下：

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，如果沒(méi)有rows.Close()，但是rows.Scan()讀取了所有的數(shù)據(jù)，那么rows的資源會(huì)自動(dòng)得到釋放；

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

如何解決？

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

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

其他原因

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

總結(jié)

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

最新評(píng)論