1、出現內存泄漏
1.1 事發現場
在風和日麗的一天，本人正看著需求、敲著代碼，展望美好的未來。突然收到一條內存使用率過高的告警。
1.2 證人證詞
告警的這個項目，老代碼是python的，最近一直在go化。隨著go化率不斷上升，發現內存的RSS使用率越飆越高。最終達到容器內存限制后，進程會自動重啟。RSS如下圖所示：
2、排查內存泄露
2.1 分析問題
看到這種不正常的RSS增長，第一反應是：是不是最近上的代碼有什么問題？是不是發生了內存泄露？內存泄露可是大事，趕緊查查。于是將時間線拉長，看看是從哪天開始的。結果，現實是很殘酷的。從項目剛上線的時候就有這個問題了。由于項目是2周一個版本，以前是還沒達到內存限制，所以沒有發出告警。
那么問題應該就是在最初的版本里。這個時候就想了想，難道是我們使用的框架本身存在缺陷？但是很快就否定了這個想法，因為我們使用的框架是其他項目已經上線已久的成熟框架。不應該有這個問題。
顯然，看代碼這種本辦法是不可能發現問題的。于是想到了golang的性能分析工具pprof。由于pprof線上環境是不開啟的，所以排查我這里只能去預發環境。
2.2 尋找問題
2.2.1 獲取內存使用監控
go tool pprof -source_path=/path/to/gopath -inuse_space https://target.service.url/debug/pprof/allocs
- -source_path Search path for source files 是分析代碼時，需要用到源碼路徑，這里就是你自己本地的gopath路徑
- /debug/pprof/allocs
- -inuse_space Same as -sample_index=inuse_space 是監控使用中的內存。因為我們分析的是內存泄露，所以要查看的是實際占用的內存
輸入以上命令，會出現以下界面的內容：
2.2.2 分析內存監控
2.2.2.1 獲取top10的內存占用
由于我們需要分析內存占用，所以這個時候輸入一個top10，看看占用內存前10的都是哪些代碼。
(pprof) top 10
Showing nodes accounting for 145.07MB, 92.64% of 156.59MB total
Dropped 163 nodes (cum <= 0.78MB)
Showing top 10 nodes out of 157
flat flat% sum% cum cum%
117.36MB 74.95% 74.95% 117.36MB 74.95% github.com/beorn7/perks/quantile.newStream (inline)
14.55MB 9.29% 84.25% 134.42MB 85.84% github.com/prometheus/client_golang/prometheus.newSummary
3.53MB 2.25% 86.50% 4.06MB 2.59% compress/flate.NewWriter
2MB 1.28% 87.77% 2MB 1.28% github.com/prometheus/client_golang/prometheus.MakeLabelPairs
1.53MB 0.97% 88.75% 1.53MB 0.97% github.com/rcrowley/go-metrics.newExpDecaySampleHeap
1.50MB 0.96% 89.71% 1.50MB 0.96% go.opentelemetry.io/otel/sdk/trace.(*recordingSpan).snapshot
1.50MB 0.96% 90.67% 1.50MB 0.96% github.com/Shopify/sarama.(*TopicMetadata).decode
1.06MB 0.68% 91.35% 1.06MB 0.68% github.com/valyala/fasthttp/stackless.NewFunc
1.03MB 0.66% 92.00% 1.03MB 0.66% github.com/xdg-go/stringprep.init
1MB 0.64% 92.64% 1MB 0.64% strings.(*Builder).WriteByte
這個時候需要解釋一下顯示的指標的含義
- flat：函數在內存上的占用
- flat%：函數在內存占用上的占用百分比
- sum%：是從上往下到當前行所有函數累加使用內存的比例 如第二行，sum=84.25=74.95+9.29
- cum：這個函數以及子函數運行所占用的內存，應該大于等于flat
- cum%：這個函數以及子函數運行所占用的內存的比例，應該大于等于flat%
2.2.2.2 查看占用函數調用棧
看完以上返回，明眼人應該就能看出，第一行這個newStream問題很大呀，讓我們進去看看他哪行代碼出了問題。需要用到一下命令
讓我們輸入list github.com/beorn7/perks/quantile.newStream一探究竟
- (pprof) list:
- Output annotated source for functions matching regexp
- 顯示具體調用的代碼塊并顯示相應指標
(pprof) list github.com/beorn7/perks/quantile.newStream
Total: 156.59MB
ROUTINE ======================== github.com/beorn7/perks/quantile.newStream in pkg/mod/github.com/beorn7/perks@v1.0.1/quantile/stream.go
117.36MB 117.36MB (flat, cum) 74.95% of Total
. . 128: sorted bool
. . 129:}
. . 130:
. . 131:func newStream(? invariant) *Stream {
. . 132: x := &stream{?: ?}
117.36MB 117.36MB 133: return &Stream{x, make(Samples, 0, 500), true}
. . 134:}
. . 135:
. . 136:// Insert inserts v into the stream.
. . 137:func (s *Stream) Insert(v float64) {
. . 138: s.insert(Sample{Value: v, Width: 1})
2.2.2.3 分析泄露原因
看到這里，應該能看出這個newStream的內存占用，主要是因為生成了一個容量為500的數組。那這個數組是什么樣的呢？
type Sample struct {
Value float64 `json:",string"`
Width float64 `json:",string"`
Delta float64 `json:",string"`
}
以上結構可以看出，生成一次需要占用的內存是50038字節，那么一次就是12000個字節,差不多是11.72kb。這么看來，應該是有個地方不停的調用，導致數據持續膨脹。看到這里，我們繼續往下追。
(pprof) list github.com/prometheus/client_golang/prometheus.newSummary
Total: 156.59MB
ROUTINE ======================== github.com/prometheus/client_golang/prometheus.newSummary in pkg/mod/github.com/prometheus/client_golang@v1.12.2/prometheus/summary.go
14.55MB 134.42MB (flat, cum) 85.84% of Total
. . 220: }
. . 221: s.init(s) // Init self-collection.
. . 222: return s
. . 223: }
. . 224:
512.12kB 512.12kB 225: s := &summary{
. . 226: desc: desc,
. . 227:
. . 228: objectives: opts.Objectives,
. . 229: sortedObjectives: make([]float64, 0, len(opts.Objectives)),
. . 230:
. 1MB 231: labelPairs: MakeLabelPairs(desc, labelValues),
. . 232:
7.03MB 7.03MB 233: hotBuf: make([]float64, 0, opts.BufCap),
7.03MB 7.03MB 234: coldBuf: make([]float64, 0, opts.BufCap),
. . 235: streamDuration: opts.MaxAge / time.Duration(opts.AgeBuckets),
. . 236: }
. . 237: s.headStreamExpTime = time.Now().Add(s.streamDuration)
. . 238: s.hotBufExpTime = s.headStreamExpTime
. . 239:
. . 240: for i := uint32(0); i < opts.AgeBuckets; i++ {
. 118.86MB 241: s.streams = append(s.streams, s.newStream())
. . 242: }
. . 243: s.headStream = s.streams[0]
. . 244:
. . 245: for qu := range s.objectives {
. . 246: s.sortedObjectives = append(s.sortedObjectives, qu)
由此看出，還不止使用一次newStream()。通過觀看代碼，我這里發現，此處的opts.AgeBuckets是等于5的，那么就意味著，循環生成了5個stream，實際上占用的內存是500*3*8*5=60000字節，也就是58.6kb。
2.2.2.4 分析調用鏈路
那么現在基本追溯完了大概的泄露原因。那怎么樣能尋找是具體的調用鏈的呢，總不能一層一層往上查找調用吧？這個時候pprof提供了一個命令，可以把整體調用生成一張圖片展示。命令如下：
go tool pprof -png -source_path=/path/to/gopath -inuse_space https://target.service.url/debug/pprof/allocs > heap.png
只需要在命令中加一個-png，那么就會生成一張圖片。當然為了方便尋找，最后可以指定圖片生成地址。我這邊抓取了和本文有關的一段截圖，如下。
根據上圖鏈路，我們大致可以看出。應該是mysql的調用，在OnFinished處，prometheus的上報的地方出現了內存泄露。這個時候我們就可以追一下OnFinished處的代碼了，因為之后的都是prometheus的調用，這是一個成熟的三方，理論不應該是他這個點出問題。
2.2.3 尋找泄露代碼
OnFinished的代碼如下：
label := append([]string{getOperation(db), s.host, s.database, tableName, hasErr, sqlState}, metrics.InjectTagValue(collector.MetricsTitle, db.Statement.Context, attachment)...)
elapsed := time.Since(s.StartTime).Seconds()
collector.DurationReporter.Collector.(prometheus.ObserverVec).WithLabelValues(label...).Observe(elapsed)看到這里我想大家就應該知道了，go代碼會為prometheus創建一個5*500的緩沖池，來記錄數據，prometheus會周期性的調用/mertic來拉取對應的內容。那么這里是怎么造成內存泄露的呢？這里就要分析上述代碼的這個label了。
func (m *MetricVec) GetMetricWithLabelValues(lvs ...string) (Metric, error) {
h, err := m.hashLabelValues(lvs)
if err != nil {
return nil, err
}
return m.metricMap.getOrCreateMetricWithLabelValues(h, lvs, m.curry), nil
}
func (m *MetricVec) hashLabelValues(vals []string) (uint64, error) {
if err := validateLabelValues(vals, len(m.desc.variableLabels)-len(m.curry)); err != nil {
return 0, err
}
var (
h = hashNew()
curry = m.curry
iVals, iCurry int
)
for i := 0; i < len(m.desc.variableLabels); i++ {
if iCurry < len(curry) && curry[iCurry].index == i {
h = m.hashAdd(h, curry[iCurry].value)
iCurry++
} else {
h = m.hashAdd(h, vals[iVals])
iVals++
}
h = m.hashAddByte(h, model.SeparatorByte)
}
return h, nil
}
2.3 發現問題（偽）
通過查看函數調用，我這邊發現label最終進入的是這個hashLabelValues中，如果已存在就返回對應的metricMap中的內容，如果不一樣，則會創建一個新的緩沖池。內存泄露就出在這個創建中。
這個時候我就在想，難道是我們label采集的數據太多了？通過排列組合，我估算了一下內存最大值
getOperation(db)=4（操作類型，增刪改查4種）
s.host=1
s.database=3（我們有3個db實例）
tableName=30（表名，保守估計最少30個）
hasErr, sqlState=2 （報錯與沒報錯2個狀態）
metrics.InjectTagValue(collector.MetricsTitle, db.Statement.Context, attachment)...
這里面記錄的是請求，保守估計最少40個接口
這樣算下來：4*1*3*30*2*40*5*500*8*3=1648mb。再加上程序本身的一些內存開銷，感覺和我們碰到的問題能對上了。
2.4 解決問題（偽）
于是一拍腦袋覺得發現了問題，但是又無法解決問題（抓的指標無法修改）。于是屁顛屁顛的升了服務器配置，將4c2g升為了4c4g。
3、解決內存泄漏
3.1 發現問題（真）
沒錯，當你看到這里的時候，就知道，升配這件事情并沒有結束。現實給了我一記響亮的耳光。
因為升配以后總覺得還是哪里有問題。于是還是每天都在不停的觀察RSS情況。結果，還真發現問題了。因為內存還在坐火箭，這不科學啊。
當我準備繼續深入研究代碼的時候，我的一位同事提醒了我，你可以去看下/metrics具體上報了什么。說時遲那時快。于是抓取了/metrics里的上報數據，看到了以下數據：
go_mysql_execute_count_total{command="SELECT",db="db_xxxxxx",endpoint="[DELETE]/url/:id",error="false",host="xxxxxx",main_table="table_xxxxxx",sql_state="0",startpoint="/url/49630"
} 1
go_mysql_execute_count_total{command="SELECT",db="db_xxxxxx",endpoint="[DELETE]/url/:id",error="false",host="xxxxxx",main_table="table_xxxxxx",sql_state="0",startpoint="/url/49631"
} 1
go_mysql_execute_count_total{command="SELECT",db="db_xxxxxx",endpoint="[DELETE]/url/:id",error="false",host="xxxxxx",main_table="table_xxxxxx",sql_state="0",startpoint="/url/49668"
} 1
go_mysql_execute_count_total{command="SELECT",db="db_xxxxxx",endpoint="[DELETE]/url/:id",error="false",host="xxxxxx",main_table="table_xxxxxx",sql_state="0",startpoint="/url/49673"
} 1
這不看不要緊，一看——原來startpoint里上報的是restful風格的請求地址。那么上面的計算緩沖池的算法，就要再乘一個無限膨脹的startpoint。這給多少個G內存也都不夠。
于是繼續查看代碼，看能不能關閉startpoint上報。這一查，果然有：
3.2 解決問題（真）
看到這個設置START_POINT的環境變量，能關閉startpoint上報。于是立馬加到生產環境后重啟服務器。上線后觀察了一段時間，RSS使用量如下圖所示：
到此，此次內存泄露問題終于排查并修復完成。真是有驚無險。
4、內存泄露問題總結
這邊大致歸納下go語言中有哪些常見的內存泄露。
常見內存泄露
4.1 Goroutine泄漏
goroutine泄露是開發過程中碰到最常見、最頻繁的。一般經常碰到的是以下幾種，由于網上相關的文章太多了，就不用代碼舉例了。
4.1.1 協程無法退出
- 鎖占用
- channel無法讀取或寫入
- 協程中邏輯有死循環?
4.1.2 協程阻塞
協程業務邏輯時間長，釋放速度跟不上生成速度4.1.3 內存使用不當
- 持續增長的常駐協程，申請了大量內存空間，由于是常駐的協程，不會釋放內存造成泄露
- 并發申請大量內存后，未達到GC時間或GC閾值，未觸發GC，導致內存泄露
4.2 結構使用不當
結構使用不當也是開發中常見的，只是可能并發不高，或者內存泄露的不多，導致使用者容易忽視掉。
4.2.1 字符串、切片截取
func main() {
var str0 = "1234567890"
str1 := str0[:5]
}
func main() {
var s0 = []int{1,2,3,4,5,6,7,8,9,0}
s1 := s0[:5]
}上面兩段代碼，會有5個字節的泄露，因為字符串和切片的兩個變量，底層是共享內存的。只要str1或s1一直在用，str0和s0就不會回收。這樣剩下的5個字節或者5個int就會有臨時的泄露。這個場景，如果在高并發，并且數據夠大的情況下，就算是臨時的泄露，也可能對性能有極大的影響。
4.2.2 指針類型
func main() {
var prt0 = []*int{new(int), new(int), new(int), new(int), new(int)}
ptr1 := prt0[:3]
}指針類型的這段代碼，其實和上面字符串、切片的例子很像，指針是指向內存地址的。只要ptr1沒釋放，前面的指針數組中未被用的指針就不會釋放，從而導致臨時的內存泄露。
4.2.3 數組傳參
func main() {
var arr1 = [3]int{1,2,3}
var arr2 = [3]int{}
arr2 = arr1
fmt.Printf("array address :%p, array : %+v \n", &arr1, arr1)
fmt.Printf("array address :%p, array : %+v \n", &arr2, arr2)
test(arr1)
}
func test(arr [3]int) {
fmt.Printf("array address :%p, array : %+v \n", &arr, arr)
}打印結果如下：
array address :0xc000122030, array : [1 2 3 4 5]
array address :0xc000122060, array : [1 2 3 4 5]
array address :0xc0001220f0, array : [1 2 3 4 5]
看結果可知，三條打印的地址各不相同，說明數組是值傳遞的，那這會有什么問題呢？畢竟我們很多代碼都是這么寫的。
問題在于，只要傳遞的這個數組足夠大，那么調用一次就會生成一個一樣大小的新地址，這樣會消耗大量內存。如果短時間內無法GC，會產生臨時的內存泄露。這種泄露對于高并發是致命的。
4.2.4 定時器
func main() {
chi := make(chan int)
go func() {
for {
timer := time.After(10 * time.Second)
select {
case <-ch:
fmt.Println("get it")
case <-timer:
fmt.Println("end")
}
}
}()
for i:= 1; i< 1000000; i++ {
chi <- i
time.sleep(time.Millisecond)
}
}以上代碼，之所以會造成內存泄露。是因為time.After的底層是實現了一個timer，只要定時器未到時間，這個定時器就不會被gc回收，從而造成臨時的內存泄露。如果這里的代碼沒寫好，定時器都是新創建的，那么就會造成永久性的泄露。
其實golang中的內存泄露遠不止上文提到的這些。有些可能甚至連查都查不到。這個時候還是要提醒大家，不僅要了解問題，還要學會查找問題。這樣不管遇到什么問題，都能發現蛛絲馬跡，問題也將迎刃而解。?
