26 程序资源监控

[TOC]

程序资源监控

对程序在运行时计算机资源使用情况进行监控，可以比较准确知道程序运行状况。

运行时资源读取

运行时可以通过定时读取并缓存 runtime.MemStats 、debug.GCStats 的数据，再通过网页获取数据分析成图表实现线上实时监控程序资源使用情况。

内存使用情况 runtime.MemStats

• Go程序在运行时可以通过读取 runtime.MemStats 获得程序内存使用情况。

• ReadMemStats 读取样本会让程序 stopTheWorld （STW）。

• ReadMemStats 不确定哪个时间（也许每分钟一次），会在固定的、非常短的时间内STW（stopTheWorld("read mem stats")），STW时间很短，但要控制读取样本频率。

• MemStats结构体，使用 GDEBUG=gctrace=1 go run main.go 【windows下开启gc日志输出 set GODEBUG=gctrace=1】命令分析一个程序GC 就会输这些字段的信息

type MemStats struct {
	// General statistics. 常规统计信息。
	// 已分配但尚未释放的字节。
	Alloc uint64
	// 累计已分配。
	TotalAlloc uint64
	// 从操作系统获取的内存总字节数（近似值）。  
	Sys uint64
	// 对象执行的指针查找的次数  。
	Lookups uint64
	// 分配的堆对象的累积计数。
	Mallocs uint64
	// 被释放的堆对象的累积计数。
	Frees uint64

	// Heap memory statistics. 分配堆内存统计。
	// 已分配但尚未释放的字节。
	HeapAlloc uint64
	// 从os为堆申请的内存大小。
	HeapSys uint64
	// 空闲 spans 字节。
	HeapIdle uint64
	// spans 使用中的最大值。
	HeapInuse uint64
	// 操作系统的物理内存大小。
	HeapReleased uint64
	// 分配的堆对象总数量。
	HeapObjects uint64

	// Stack memory statistics. 栈内存统计
	// stack不是heap的一部分，但runtime可以将heap内存的一部分用于stack，反之亦可。
	// 在stack span的字节。
	StackInuse uint64
	// 从操作系统中获取的stack内存。
	StackSys uint64

	// Off-heap memory statistics. 堆外内存统计信息
	// 分配的mspan结构的字节。
	MSpanInuse uint64
	// 从操作系统中获取的用于mspan结构的字节。
	MSpanSys uint64
	// 已分配的mcache结构的字节。
	MCacheInuse uint64
	// 从操作系统中分配的mcache结构的字节。
	MCacheSys uint64
	// 分析bucket哈希表中的内存字节。
	BuckHashSys uint64
	// GC中元数据的字节。
	GCSys uint64
	// 其它堆外runtime分配的字节。
	OtherSys uint64

	// Garbage collector statistics. 垃圾回收器统计信息
	// 下次GC目标堆的大小。
	NextGC uint64
	// 上次GC完成的UNIX时间戳。
	LastGC uint64
	// 从程序开始时累计暂停时长(STW)纳秒。
	PauseTotalNs uint64
	// 最近一次的STW时间缓存区，最近一次暂停是在 PauseNs[(NumGC+255)%256]，通常它是记录最近 N%256 次的GC记录。
	PauseNs [256]uint64
	// 最近GC暂停的缓冲区，缓冲区的存放方式与PauseNs一样。每个GC有多个暂停，记录最后一次暂停。
	PauseEnd [256]uint64
	// 完成的GC数量。
	NumGC uint32
	// 记录应用通过调用 GC 函数强制GC的次数。
	NumForcedGC uint32
	// 自程序启动后GC使用CPU时间的分值，其值为0-1之间，0表示gc没有消耗当前程序的CPU（不包括写屏障的cpu时间）。
	GCCPUFraction float64
	// 启用GC值为true，除非使用GOGC=off设置。
	EnableGC bool
	// DebugGC is currently unused.当前未使用。
	DebugGC bool
	
	// 按 per-size class 大小分配统计
	BySize [61]struct {
		// Size is the maximum byte size of an object in this
		Size uint32
		// Mallocs is the cumulative count of heap objects
		Mallocs uint64
		// Frees is the cumulative count of heap objects freed
		Frees uint64
	}

通过 expvar 包 HTTP 请求获取内存使用情况

HTTP 请求获取 runtime.MemStats

• Go 提供了 expvar 包，可以通过HTTP请求获取服务运行 runtime.MemStats 的 JSON 数据。

• expvar 包提供的 expvar.Handler()函数获取控制器，通过访问这个控制器获得数据，其内部也是调用 runtime.ReadMemStats(&runtime.MemStats) 读取数据。

	// 访问 http://localhost:8080/stats 
	// 或者 http://localhost:8080/debug/vars 获取数据
	http.Handle("/stats", expvar.Handler())
	http.ListenAndServe(":8080", nil)

最近 GC 状况 debug.GCStats 获取

runtime/debug.GCStats 是最近的垃圾收集情况的数据，通过 debug.ReadGCStats() 函数读取数据。

• debug.GCStats 结构的字段

// 最近的垃圾收集的信息
type GCStats struct {
    // 上次收集时间
	LastGC         time.Time   
	// 垃圾回收次数
	NumGC          int64
	// 总暂停时长
	PauseTotal     time.Duration   
	// 暂停历史，前面的是最近的
	Pause          []time.Duration 
	// 暂停结束的时间点，前面的是最近的
	PauseEnd       []time.Time     
	// 暂停时间分位，长度为5填充最小、25%、50%、75% 、最大暂停时间，
	// 如果为100则是1%到100%。
	PauseQuantiles []time.Duration
}

• debug.ReadGCStats() 读取 GC 数据

	gcStatsP := &debug.GCStats{PauseQuantiles: make([]time.Duration, 5)}
	debug.ReadGCStats(gcStatsP)

运行时资源使用情况读取案例

运行时资源使用情况读取案例

• 内存情况 runtime.ReadMemStats(&runtime.MemStats)

• GC情况 debug.ReadGCStats(&debug.GCStats)

package main

import (
	"fmt"
	"runtime"
	"runtime/debug"
	"time"
)

func main() {
	ch := make(chan int,1)
	for i:=0;i<5;i++{
		go testA(ch)
	}
	for i:=0;i<100000;i++{
		ch <- 1
	}
	// 调用 GC 函数强制GC，这个次数会在 NumForcedGC 字段统计出
	runtime.GC()	
	time.Sleep(1*time.Second)
	for i:=0;i<100000;i++{
		ch <- 1
	}
	close(ch)
	runtime.GC()
	time.Sleep(1*time.Second)
	var m runtime.MemStats
	runtime.ReadMemStats(&m)
	fmt.Printf("常规统计信息：已分配但尚未释放=%v，累计已分配%v，获取的内存总字节数=%v，指针查找的次数=%v，分配的堆对象的累积计=%v，被释放的堆对象的累积计=%v \n",m.Alloc,m.TotalAlloc,m.Sys,m.Lookups,m.Mallocs,m.Frees)
	fmt.Printf("分配堆内存统计：已分配但尚未释放=%v，从os为堆申请的=%v，空闲 spans 字节=%v，使用中的最大值=%v，系统的物理内存大小=%v，分配的堆对象总数量=%v \n",m.HeapAlloc,m.HeapSys,m.HeapIdle,m.HeapInuse,m.HeapReleased,m.HeapObjects)
	fmt.Printf("栈内存统计：在栈span的字节=%v，操作系统中获取的栈内存=%v \n",m.StackInuse,m.StackSys)
	fmt.Printf("堆外内存统计：分配的mspan结构的字节=%v，从操作系统中获取的用于mspan结构的字节=%v，已分配的mcache结构的字节=%v，操作系统中分配的mcache结构的字节=%v，分析bucket哈希表中的内存字节=%v，GC中元数据的字节=%v，其它堆外runtime分配的字节=%v \n",m.MSpanInuse,m.MSpanSys,m.MCacheInuse,m.MCacheSys,m.BuckHashSys,m.GCSys,m.OtherSys)
	fmt.Printf("垃圾回收器统计：下次GC目标堆的大小=%v，上次GC完成的UNIX时间戳=%v，累计暂停时长(STW)纳秒=%v，完成的GC数量=%v，调用 GC 函数强制GC的次数=%v，自程序启动后GC使用CPU时间的分值=%v，启用GC=%v \n",m.NextGC,m.LastGC,m.PauseTotalNs,m.NumGC,m.NumForcedGC,m.GCCPUFraction,m.EnableGC)

	gcStatsP := &debug.GCStats{PauseQuantiles: make([]time.Duration, 5)}
	debug.ReadGCStats(gcStatsP)
	fmt.Printf("上次垃圾回收时间：%v，垃圾收集次数：%v，总暂停时间：%v \n",gcStatsP.LastGC,gcStatsP.NumGC,gcStatsP.PauseTotal)
	fmt.Println("暂停历史：",gcStatsP.Pause[0])
	fmt.Println("暂停结束的时间点：",gcStatsP.PauseEnd[0])
	fmt.Println(gcStatsP.PauseQuantiles)
}

func testA(ch <- chan int){
	for {
		_,isOpen := <- ch
		if !isOpen {
			return
		}
		buf := make([]byte,1024000)
		buf[0] = 1
	}
}

常规统计信息：已分配但尚未释放=2361832，累计已分配204801489264，获取的内存总字节数=77946064，指针查找的次数=0，分配的堆对象的累积计=213288，被释放的堆对象的累积计=212189 
分配堆内存统计：已分配但尚未释放=2361832，从os为堆申请的=71008256，空闲 spans 字节=68239360，使用中的最大值=2768896，系统的物理内存大小=46759936，分配的堆对象总数量=1099 
栈内存统计：在栈span的字节=294912，操作系统中获取的栈内存=294912 
堆外内存统计：分配的mspan结构的字节=131104，从操作系统中获取的用于mspan结构的字节=180224，已分配的mcache结构的字节=18688，操作系统中分配的mcache结构的字节=32768，分析bucket哈希表中的内存字节=5876，GC中元数据的字节=4144528，其它堆外runtime分配的字节=2279500 
垃圾回收器统计：下次GC目标堆的大小=4727456，上次GC完成的UNIX时间戳=1644908273336103200，累计暂停时长(STW)纳秒=2265243200，完成的GC数量=33717，调用 GC 函数强制GC的次数=1，自程序启动后GC使用CPU时间的分值=0.26847586571520604，启用GC=true 
上次垃圾回收时间：2022-02-15 14:57:53.3361032 +0800 CST，垃圾收集次数：33717，总暂停时间：2.2652432s 
暂停历史： 0s
暂停结束的时间点： 2022-02-15 14:57:53.3361032 +0800 CST
[0s 0s 0s 0s 1.0694ms]

GODEBUG 和 垃圾回收跟踪

运行时中调试变量 GODEBUG

linux环境下修改GODEBUG参数使用 【GDEBUG=参数=值】 ，windows环境下修改GODEBUG参数使用 【set GODEBUG=参数=值】

• linux 下开启gc日志跟踪并运行程序：GDEBUG=gctrace=1 go run main.go

• windows 下开启gc日志跟踪和运行程序要分两行命令：set GODEBUG=gctrace=1 ， go run main.go

GODEBUG 参数：

allocfreetrace

• 设置 allocfreetrace=1 会导致每次分配分析并在每个对象的分配和空闲上打印堆栈跟踪。

clobberfree

• 设置 clobberfree=1 会导致垃圾收集器 释放时破坏具有不良内容的对象的内存内容 物体。

cgocheck

• 设置 cgocheck=0 禁用对包的所有检查 使用 cgo 错误地将 Go 指针传递给非 Go 代码。 设置 cgocheck=1 （默认）启用相对便宜 检查可能会遗漏一些错误。设置 cgocheck=2 启用 昂贵的检查不应该错过任何错误，但会 导致您的程序运行速度变慢。

efence

• 设置 efence=1 使分配器在一个模式下运行 其中每个对象都分配在一个唯一的页面上，地址是 从未回收。

gccheckmark

• 设置 gccheckmark=1 启用验证 垃圾收集器的并发标记阶段通过执行 当世界停止时，第二个标记通过。如果第二个 pass 找到并发未找到的可达对象 标记，垃圾收集器会恐慌。

gcpacertrace

• 设置 gcpacertrace=1 会导致垃圾收集器 打印有关并发起搏器内部状态的信息。

gcshrinkstackoff

• 设置 gcshrinkstackoff=1 禁用移动 goroutine 到较小的堆栈上。在这种模式下，goroutine 的堆栈只能增长。

gcstoptheworld

• 设置 gcstoptheworld=1 禁用并发垃圾收集， 使每次垃圾收集都成为世界末日的事件。设置 gcstoptheworld=2 垃圾收集完成后还会禁用并发扫描。

gctrace

• 设置 gctrace=1 会导致垃圾收集器向标准发出一行 每次收集的错误，总结收集的内存量和 停顿的长度。

gctrace数据行的格式：
	gc # @#s #%: #+#+# ms 时钟，#+#/#/#+# ms cpu，#->#-># MB，# MB 目标，# P
其中字段如下：
	gc # GC 编号，每次 GC 递增
	@#s 自程序启动以来的时间（以秒为单位）
	#% 自程序启动以来花费在 GC 上的时间百分比
	#+...+# GC 阶段的挂钟/CPU 时间
	#->#-># GC 开始时、GC 结束时和活动堆时的 MB 堆大小
	# MB 目标目标堆大小
	# P 使用的处理器数量
阶段是停止世界（STW）扫描终止，并发
标记和扫描，以及 STW 标记终止。CPU 时间
用于标记/扫描被分解为辅助时间（GC 执行于
line with allocation)、后台 GC 时间和空闲 GC 时间。
如果该行以“（强制）”结尾，则此 GC 是由
runtime.GC() 调用。

inittrace

• 设置 inittrace=1 会导致运行时向标准发出单行 带有init work的每个包的错误，总结了执行时间和内存 分配。作为插件加载的一部分执行的初始化不会打印任何信息 对于没有用户定义和编译器生成的初始化工作的包。

inittrace数据行的格式：
	init # @#ms, # ms 时钟, # bytes, # allocs
其中字段如下：
	init # 包名
	@# 自程序启动以来 init 启动的毫秒时间（以毫秒为单位）
	# 包初始化工作的时钟挂钟时间
	# 在堆上分配的字节内存
	# allocs 堆分配的数量

madvdontneed

• 设置 madvdontneed=0 将使用 MADV_FREE 将内存返回到 核心。这更有效，但意味着 RSS 号码将 仅当操作系统处于内存压力下时才下降。

memprofilerate

• 设置 memprofilerate=X 将更新 runtime.MemProfileRate 的值。 当设置为 0 时，内存分析被禁用。参考描述 MemProfileRate 为默认值。

invalidptr

• invalidptr=1（默认）导致垃圾收集器和堆栈 如果指针值无效（例如，1），则复制器使程序崩溃 在指针类型的位置中找到。设置 invalidptr=0 禁用此检查。 这应该仅用作诊断错误代码的临时解决方法。 真正的解决方法是不要将整数存储在指针类型的位置。

sbrk

• 设置 sbrk=1 替换内存分配器和垃圾收集器 使用从操作系统获取内存的普通分配器和 永远不会回收任何记忆。

scavtrace

• 设置 scavtrace=1 会导致运行时向标准发出单行 错误，大约每个 GC 周期一次，总结了 scavenger 以及返回给操作系统的内存总量 以及物理内存利用率的估计。

scavtrace数据行的格式
	scav # # KiB work, # KiB total, #% util
其中字段如下：
	scav # 清除周期数
	# KiB work 自上一行以来返回给操作系统的内存量
	# KiB total 返回给操作系统的内存总量
	#% util 正在使用的所有未清理内存的比例
如果该行以“（强制）”结尾，则清除是由
debug.FreeOSMemory() 调用。

scheddetail

• 设置 schedtrace=X 和 scheddetail=1 会导致调度程序发出 每 X 毫秒详细的多行信息，描述调度程序的状态， 处理器、线程和 goroutines。

schedtrace

• 设置 schedtrace=X 会导致调度程序将单行发送到标准 每 X 毫秒出错一次，总结调度程序状态。

tracebackancestors

• 设置 tracebackancestors=N 使用堆栈扩展回溯 创建了哪些 goroutine，其中 N 将祖先 goroutine 的数量限制为 报告。这也扩展了 runtime.Stack 返回的信息。祖先的 goroutine IDs 将引用 goroutine 在创建时的 ID；这是可能的 用于另一个 goroutine 的 ID。将 N 设置为 0 将不报告祖先信息。

asyncpreemptoff

• asyncpreemptoff=1 禁用基于信号的 异步 goroutine 抢占。这会产生一些循环 长时间不可抢占，这可能会延迟 GC 和 goroutine 调度。这对于调试 GC 问题很有用 因为它还禁用了使用的保守堆栈扫描 用于异步抢占 goroutine。

垃圾回收跟踪 gctrace 数据分析

GODEBUG 提供的 gctrace 跟踪垃圾回收数据在本地环境和测试环境中使用效果很好，通过模拟采集数据结果进行分析找出程序瓶颈。

• set GODEBUG=gctrace=1

• go run demo.go

• 运行程序后输出：

gc 1 @0.020s 0%: 0.010+0.57+0 ms clock, 0.16+0.12/0.062/0+0 ms cpu, 4->4->0 MB, 5 MB goal, 16 P
gc 2 @0.025s 0%: 0+0+0 ms clock, 0+0/0/0+0 ms cpu, 4->4->0 MB, 5 MB goal, 16 P
gc 3 @0.030s 0%: 0+0.50+0 ms clock, 0+1.0/2.0/2.0+0 ms cpu, 4->4->0 MB, 5 MB goal, 16 P
gc 4 @0.046s 0%: 0+0.52+0 ms clock, 0+0/2.1/1.6+0 ms cpu, 4->4->0 MB, 5 MB goal, 16 P
gc 5 @0.064s 0%: 0+1.0+0 ms clock, 0+0/0/0+0 ms cpu, 4->4->0 MB, 5 MB goal, 16 P
......
gc 36391 @46.027s 7%: 0+1.2+0.068 ms clock, 0+1.9/3.3/1.3+1.0 ms cpu, 10->10->3 MB, 11 MB goal, 16 P
gc 36392 @46.029s 7%: 0+0+0 ms clock, 0+0/0/0+0 ms cpu, 8->8->3 MB, 9 MB goal, 16 P
gc 36393 @46.030s 7%: 0+0+0 ms clock, 0+0/0/0+0 ms cpu, 8->8->3 MB, 9 MB goal, 16 P
gc 36394 @46.031s 7%: 0+0+0 ms clock, 0+0/0/0+0 ms cpu, 9->10->4 MB, 10 MB goal, 16 P (forced)
gc 36395 @46.032s 7%: 0+0+0 ms clock, 0+0/0/0+0 ms cpu, 8->8->0 MB, 9 MB goal, 16 P (forced)

对最后一行的列数据进行分析，第4列是垃圾回收STW时间，第5列是垃圾回收GC占CPU时间信息，第6列是内存信息

• 第1列：【gc 36395】 第36395次gc，GC 编号，每次 GC 递增。

• 第2列：【@46.032s】 这次gc的markTermination（标记终止）阶段完成后，距离程序启动到现在的时间。

• 第3列：【7%】 到目前为止gc的标记工作（包括两次标记阶段的STW和并发标记）所用的CPU时间占总CPU的百分比。

• 第4列：【0+0+0 ms clock】 这里三个数字按+号拆分成三部分，第一部分是标记阶段的STW时间（单逻辑处理器）；第二部分是并发标记用的时间（所有逻辑处理器）；第三部分是标记终止阶段的STW时间（单逻辑处理器）。

• 第5列：【0+0/0/0+0 ms cpu】三组数字按+号和/拆分成五部分，第一部分是整个进程在mark（标记）阶段STW的时间，第二部分是mutator assists（协助标记协程）占用的时间，第三部分是dedicated mark workers（标记专用协程） + fractional mark worker（辅助标记协程）占用的时间，第四部分是idle mark workers（会被抢占执行权的辅助标记协程） 占用的时间，第五部分是进程在markTermination（标记终止）阶段STW时间。

• 第6列：【8->8->0 MB】按->分成三部分，第一部分是标记阶段前的 heap_live 大小，第二部分是标记终止前的 heap_live 大小；第三部分是被标记对象的大小。

• 第7列：【 9 MB goal】 下一次触发GC的内存占用阀值是9MB。

• 第8列：【16 P (forced)】本次gc共有多少个逻辑处理器。

gctrace 数据可视化 gcvis

gcvis 逐行解析目标程序的 GC 输出，然后用正则匹配相关的数据，生成 JSON 格式数据，另外启动一个协程开启 HTTP 服务展示图表。

• 下载 gcvis 源码 https://github.com/davecheney/gcvis ，使用 go build 编译成可执行程序，或者 go get github.com/davecheney/gcvis 直接安装gcvis。

ubuntu20 下使用 gcvis（Linux下使用基本雷同）

• 安装gcvis： go get github.com/davecheney/gcvis

• 管道重定向方式一边运行不断监控：GODEBUG=gctrace=1 go run main.go |& gcvis

• 或者直接运行：gcvis go run main.go

• 运行gcvis后会启动一个HTTP服务器，HTML网页中图表会不断刷新数据。

内存数据图表，【运行时资源使用情况读取案例】

• gc.heapinuse 堆使用

内存数据图表

内存数据图表

STW数据图表

• STW sweep clock 清扫STW耗时

• STW mark clock 标记STW耗时

STW数据图表

STW数据图表

CPU数据图表

• STW sweep cpu 清扫占用cpu时间

• STW mark cpu 标记占用cpu时间

CPU数据图表

CPU数据图表

开源监控系统介绍

生产环境中可以选择使用开源的监控系统对 Go 服务器程序进行监控。

• 常见开源监控报警系统 Prometheus、Open-falcon（小米），都支持多通道的告警源、支持多通道的告警目标。

• Prometheus 和 Open-falcon，监控系统和报警系统都可以单独的部署，相比 Open-falcon，Prometheus 报警规则更加灵活，满足更多场景的需求。

• Open-falcon 使用 Python/Go开发，部署需要Python、MySQL、Redis等等环境，Prometheus 使用Go开发，无须额外环境。