背景:
kubelet被重启后, 内存再次升高, 在游戏启动后,没有进入大量玩家的情况下,2天时间占用接近10G,并且持续在增长, CPU偶尔负载高。AWS给出的解释是containerd v1.4.0版本问题, 以下为内部分析过程。
实际情况
|
CPU分析
1)整体分析:runtime.scanobject(gc垃圾回收相关)函数占用CPU最多,耗时最长
性能调试
|
2)火焰图(横轴表示运行时间,可以观察程序不同部分的占比,纵轴表示函数调用栈)
分析:kubelet的cpu表现偶尔异常,大部分情况正常,但是能从中看出来负责垃圾回收的gc线程最为忙碌,runtime.gcBgMarkWorker 函数,这个函数是 golang 垃圾回收相关的函数,用于标记(mark)出所有是垃圾的对象。一般情况下此函数不会占用这么多的 cpu,出现这种情况一般都是内存 gc 问题,但是后续内存占用只比平常多了几百M,并没有特别高,原因是影响 GC 性能的一般都不是内存的占用量,而是对象的数量。举例说明,10 个 100m 的对象和一亿个 10 字节的对象占用内存几乎一样大,但是回收起来一亿个小对象肯定会比 10 个大对象要慢很多。
火焰图分析
# go tool pprof -http localhost:8001 ~/Documents/pprof.kubelet.samples.cpu.002.pb.gz
|
编辑
内存分析
1)整体分析:kubelet总共占据了9.86G左右内存, 主要由两个函数造成分配内存过多:
encoding/json.(*decodeState).literalStore | 7.4G |
reflect.unsafe_NewArray | 2.1G |
heap
➜ ~ go tool pprof http://10.90.32.42:8001/api/v1/nodes/ip-10-90-154-0.cn-north-1.compute.internal/proxy/debug/pprof/heap Fetching profile over HTTP from http://10.90.32.42:8001/api/v1/nodes/ip-10-90-154-0.cn-north-1.compute.internal/proxy/debug/pprof/heap Saved profile in /Users/westos/pprof/pprof.kubelet.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz File: kubelet Build ID: fa0e6afcd119e92cd898064c5f918d9dc46a9676 Type: inuse_space Time: Dec 8, 2020 at 6:40am (CST) Entering interactive mode (type "help" for commands, "o" for options) (pprof) top Showing nodes accounting for 10031.25MB, 99.40% of 10091.96MB total Dropped 224 nodes (cum <= 50.46MB) Showing top 10 nodes out of 20 flat flat% sum% cum cum% 7593.96MB 75.25% 75.25% 7593.96MB 75.25% encoding/json.(*decodeState).literalStore 2223.15MB 22.03% 97.28% 2223.15MB 22.03% reflect.unsafe_NewArray 213.63MB 2.12% 99.39% 214.63MB 2.13% k8s.io/kubernetes/vendor/github.com/docker/docker/pkg/stdcopy.StdCopy 0.50MB 0.005% 99.40% 9850.17MB 97.60% k8s.io/kubernetes/pkg/kubelet/dockershim.(*dockerService).ExecSync 0 0% 99.40% 9833.62MB 97.44% encoding/json.(*Decoder).Decode 0 0% 99.40% 9799.61MB 97.10% encoding/json.(*decodeState).array 0 0% 99.40% 9833.62MB 97.44% encoding/json.(*decodeState).object 0 0% 99.40% 9833.62MB 97.44% encoding/json.(*decodeState).unmarshal 0 0% 99.40% 9833.62MB 97.44% encoding/json.(*decodeState).value 0 0% 99.40% 9848.67MB 97.59% k8s.io/kubernetes/pkg/kubelet/dockershim.(*streamingRuntime).exec (pprof) list literalStore Total: 9.86GB ROUTINE ======================== encoding/json.(*decodeState).literalStore in /usr/local/go/src/encoding/json/decode.go 7.42GB 7.42GB (flat, cum) 75.25% of Total . . 1005: break . . 1006: } . . 1007: if v.NumMethod() != 0 { . . 1008: d.saveError(&UnmarshalTypeError{Value: "number", Type: v.Type(), Offset: int64(d.readIndex())}) . . 1009: break 7.42GB 7.42GB 1010: } . . 1011: v.Set(reflect.ValueOf(n)) . . 1012: . . 1013: case reflect.Int, reflect.Int8, reflect.Int16, reflect.Int32, reflect.Int64: . . 1014: n, err := strconv.ParseInt(s, 10, 64) . . 1015: if err != nil || v.OverflowInt(n) { (pprof) (pprof) list unsafe_NewArray Total: 9.86GB ROUTINE ======================== reflect.unsafe_NewArray in /usr/local/go/src/runtime/malloc.go 2.17GB 2.17GB (flat, cum) 22.03% of Total . . 1173://go:linkname reflectlite_unsafe_New internal/reflectlite.unsafe_New . . 1174:func reflectlite_unsafe_New(typ *_type) unsafe.Pointer { . . 1175: return mallocgc(typ.size, typ, true) . . 1176:} . . 1177: 2.17GB 2.17GB 1178:// newarray allocates an array of n elements of type typ. . . 1179:func newarray(typ *_type, n int) unsafe.Pointer { . . 1180: if n == 1 { . . 1181: return mallocgc(typ.size, typ, true) . . 1182: } . . 1183: mem, overflow := math.MulUintptr(typ.size, uintptr(n)) (pprof) |
2)火焰图(从上至下,函数调用栈)
分析:
- 1)该调用栈主要是在获取容器状态, 最后一个位于kubelet代码中的函数为 k8s.io/kubernetes/vendor/github.com/docker/docker/client.(*Client).ContainerInspect,获取容器信息
- 2)decodeState方法导致大量的小内存对象需要被分配,其中literalStore类型最多, 64B的对象已经使用了高达124620205个(1.2亿), 64B * 124620205 / (1024 * 1024) = 7.6G
- 3)结合上面的CPU火焰图,垃圾回收gc函数比较忙碌,侧面说明小对象非常多。
编辑
--inuse/inuse_objects, 对象使用数量,decodeState使用64B的对象达到1.2亿,且还在增长
编辑
--inuse/inuse_space 内存使用量,decodeState累计小对象总内存已接近8G, 随着时间推移,还在增长。
编辑
总结:
1)CPU整体表现正常,偶尔异常, 异常时gc垃圾回收最为忙碌, 大部分时间正常说明即时有这么多小对象产生,但是回收量并不高,否则cpu使用率应该会非常高
2)内存方面,dockershim.(*streamingRuntime).exec调用产生的小对象数量非常多,且回收很少,导致内存不断增长
3)虽然能确定内存是因为小对象分配过多,且回收量很少, 但是具体的为何CRI(容器运行时相关代码)检查容器状态时产生这么多的小对象,是否存在失败不停重试还需要结合kubernetes CRI部分源码和kubelet、container-shim、docker三者的关系以及日志来深入分析进行定位。
4)strace并未能追踪到kubelet的函数调用栈及出错次数(原因未知)
经验总结
在做内存问题相关的排查时:
- 若 gc 相关函数占用异常,可重点排查对象数量
- 解决速度问题(CPU占用)时,关注对象数量( --inuse/alloc_objects )指标
- 解决内存占用问题时,关注分配空间( --inuse/alloc_space )指标
后边我将会给大家带来更多内存、CPU异常分析工具和方法,敬请关注