前言
最近接到几个关于在压力测试下，pod 中的容器被重启的问题。在查看了下 pod 的信息及使用 dmesg 命令到 node 节点上查看了一下系统日志，发现都是我们的 golang 容器的内存达到了我们设置的 limit 的值，从而导致了 OOMKilled 了。
分析
既然我们查到是我们的程序发生了 OOMKilled，那我们就好分析优化了。
编写 benchmark 程序
编写一个类似下面的 Benchmark 程序。
func Benchmark_ServeHTTP(b *testing.B) {
for i := 0; i < b.N; i++ {
rr := httptest.NewRecorder()
req, _ := http.NewRequest(method, url, bytes.NewBuffer(data))
req.Header.Set("content-type", "application/json")
h.ServeHTTP(rr, req)
}
}
测试及结果分析
使用 golang 提供的 test 和 tool 工具去测试及分析内存使用情况。
cd benchmark;
go test -bench=. --run=none -memprofile=newmem.pprof -benchmem;
go tool pprof newmem.pprof
我们 使用 top 命令可以看到下面的内存使用信息。
18172 309756 ns/op 18802 B/op 250 allocs/op
PASS
(pprof) top 20
Showing nodes accounting for 381.38MB, 75.53% of 504.92MB total
Dropped 55 nodes (cum <= 2.52MB)
Showing top 20 nodes out of 113
flat flat% sum% cum cum%
58.52MB 11.59% 11.59% 186.31MB 36.90% xxxx/xxxx/xxxx/golog.logWithFields
56.55MB 11.20% 22.79% 56.55MB 11.20% go.uber.org/zap/buffer.NewPool.func1
28.51MB 5.65% 28.44% 29.01MB 5.75% net/textproto.MIMEHeader.Set (inline)
27.51MB 5.45% 33.88% 27.51MB 5.45% net/http.Header.Clone
25MB 4.95% 38.84% 25MB 4.95% xxxx/xxxx/xxxx/xxxx/xxxx/ports/pm.Increase
18.01MB 3.57% 42.40% 18.01MB 3.57% encoding/json.(*Decoder).refill
17.50MB 3.47% 45.87% 17.50MB 3.47% encoding/json.Marshal
17MB 3.37% 49.24% 26MB 5.15% net/http.NewRequestWithContext
15MB 2.97% 52.21% 15MB 2.97% net/textproto.canonicalMIMEHeaderKey
14MB 2.77% 54.98% 313.83MB 62.15% xxxx/xxxx/xxxx/xxxx/xxxx/domain/service.(*Subscription).Create
接下来我们可以使用 list function name 命令去查看具体的函数使用的内存情况。
NOTE: 当使用 list 命令查看自己程序的时候，如果提示找不到 source 信息，可以在 go tool pprof 后面指定保存在本地的被 profile 程序的 binary 文件，并且这个 binary 文件要和生成 profile 文件的程序是在同一平台下编译的。
优化
当使用 list 查看了程序内存使用的大户之后，就需要着手优化这部分代码。这里不具体的展示代码了，只介绍部分思路。
-
在将 []byte 转换为 string 的时候，强制转换的话，会导致重新分配空间，使用直接取地址的方式，可以节省这部分空间。
func toString(s []byte) string { return *(*string)(unsafe.Pointer(&s)) } -
替换 zap 打印 log 的方式，从
logger.With(logFields...).Info(message)替换为logger.Info(decorateString(msg), logFields...) -
减少内存逃逸。
这里我们的 log 打印是有等级的控制，也就是说当 level 是 info 的时候，debug 的 log 并不会打印。所以对于这类 debug log，如果在这种情况下，还会分配内存，是很不好的情况，因为我们的 debug 的日志会比较多。
那为什么这里会有内存分配呢，是因为发生了内存逃逸。是由于我们的打印日志的函数的接口是有 interface{}，按照 golang 的机制，会在编译期将这部分变量逃逸到堆内存上。
解决这个问题，我们可以用 string 类型替换 interface{} 类型。
-
减少不必要的变量分配。
也就是说将变量的初始化到必要时。这里我们的情况是对于 http headers 的拷贝。由于我们是支持 tracing header 的，所以对于正常消息，我们必须将 headers 传输给下一跳，并将下一跳的 tracing header 回复到上一跳。所以对于正常消息，这种不可避免 http headers 的拷贝，因为我们需要将 request 的 tracing header 拷贝到一个变量进行传递，。 但是对于异常消息，例如上一跳信息的验证失败，服务 overloaded，这种情况下，并不需要这样的一个变量，可以直接将上一跳的 request tracing header 写入到 response header 中。
优化后的结果
25738 233983 ns/op 11649 B/op 179 allocs/op
PASS
(pprof) top 20
Showing nodes accounting for 271.85MB, 72.70% of 373.92MB total
Dropped 61 nodes (cum <= 1.87MB)
Showing top 20 nodes out of 110
flat flat% sum% cum cum%
41.01MB 10.97% 10.97% 43.01MB 11.50% net/textproto.MIMEHeader.Set (inline)
21.51MB 5.75% 16.72% 21.51MB 5.75% net/http.Header.Clone
19MB 5.08% 21.80% 19MB 5.08% net/textproto.canonicalMIMEHeaderKey
18.01MB 4.82% 26.62% 18.01MB 4.82% encoding/json.(*Decoder).refill
17.50MB 4.68% 31.30% 17.50MB 4.68% encoding/json.Marshal
16.01MB 4.28% 35.58% 16.51MB 4.41% io.ReadAll
16MB 4.28% 39.86% 27MB 7.22% net/http.NewRequestWithContext
12MB 3.21% 43.07% 168.81MB 45.14% xxxx/xxxx/xxxx/xxxx/xxxx/domain/service.(*Subscription).Create
11.50MB 3.08% 46.15% 22.01MB 5.89% golang.org/x/net/http2.(*Transport).newTLSConfig
10.50MB 2.81% 48.95% 10.50MB 2.81% crypto/tls.(*Config).Clone
可以看到基本上减少了接近一半的内存使用。
总结
首先，不得不说 golang 的内存调优还是很方便的，因为它提供了方便的工具给你使用。其实除了这里本地做内存分析之外，还可以使用 pprof 查看程序运行时的内存使用，从而根据真实的 traffic 进行内存分析。
其次，在做内存分析的时候，现在要选择那些内存使用大户，将它们优化到一定程度，那将会有很乐观的结果。这里我们的程序中，主要是使用的封装了 zap 的 log 库，及封装了 pm 的库及 http headers 的拷贝占用了绝大部分内存，因为这些在之前的程序中每条信息都是需要处理的。
所以我优化了 log 的库，及对 pm 库的使用，及避免了不需要的 http headers 的拷贝。