跳至正文

Go 环境变量 – GODEBUG 详解

简介

GODEBUG 环境变量可以控制程序运行时的调度信息输出,方便开发者了解内部细节。

语法是通过逗号分割多个键值对,例如:

# 运行 main.go, 每秒输出 1 次调度信息
$ GODEBUG=scheddetail=1,schedtrace=1000 go run main.go

常用参数

名称描述
scheddetail1设置 schedtrace=X 和 scheddetail=1, 每 X 毫秒输出 1 次调度信息
schedtraceX每 X 毫秒输出 1 次调度信息
allocfreetrace1监控每次分配,分析和打印每个对象的分配和释放的调用堆栈
cgocheck[0, 1, 2]CGO 是否检查 Go 指针传递给非 Go 代码, 0: 禁用 1: 弱检查 2: 强检查
efence1让分配器把每个对象都分配在一个唯一的从未回收的页面
gccheckmark1启用 GC 执行并发标记
gcpacertrace1打印并发 pacer 的内部状态
gcshrinkstackoff1禁用移动 goroutines 到较小的栈上,在这种模式下,goroutine 的栈只能增长
gcstoptheworld1禁用并发 GC,每次 GC 都会触发 STW
gctrace1每次 GC 时输出一行日志,统计内存回收和暂停时间
memprofilerate[0, X]0: 禁用 X: 更新 runtime.MemProfileRate 的值

示例程序

本文后面的几个用例,全部使用该程序演示。

package main

import (
 "sync"
 "time"
)

func main() {
 var wg sync.WaitGroup

 for i := 0; i < 10; i++ {
  wg.Add(1)

  go func() {
   defer wg.Done()

   time.Sleep(1 * time.Second)
  }()
 }

 wg.Wait()
}

输出调度基础信息

执行命令

$ GODEBUG=schedtrace=1000 go run main.go

# 输出如下
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=0 runqueue=0 [1 0 0 0 0 0 0 0]

...

SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=2 runqueue=0 [0 0 0 0 0 0 0 0]
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=5 spinningthreads=1 idlethreads=2 runqueue=0 [9 0 0 0 0 0 0 0]
SCHED 1007ms: gomaxprocs=8 idleprocs=8 threads=13 spinningthreads=0 idlethreads=6 runqueue=0 [0 0 0 0 0 0 0 0]

输出结果说明

名称描述
SCHED标志字符串,代表 goroutine 调度器
0ms从程序启动到输出这行日志的时间
gomaxprocsP 的数量,(默认的 P 和 CPU 核心数量一致
idleprocs空闲状态的 P 的数量
threads线程数量
spinningthreads自旋状态的线程数量
idlethread空闲状态的线程数量
runqueue全局队列中 G 的数量
[0 … 0]每个 P 的本地队列中 G 的数量

输出 GC 时内存示例

执行命令

$ GODEBUG=gctrace=1 go run main.go

# 输出如下
gc 1 @0.028s 1%: 0.058+1.1+0.19 ms clock, 0.46+0/1.0/0.36+1.5 ms cpu, 3->4->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 2 @0.034s 1%: 0.083+0.63+0.005 ms clock, 0.66+0.094/0.51/0.27+0.044 ms cpu, 3->3->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 3 @0.039s 1%: 0.031+0.66+0.042 ms clock, 0.25+0.091/0.49/0.39+0.34 ms cpu, 3->4->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 4 @0.043s 2%: 0.027+0.70+0.14 ms clock, 0.22+0.039/0.50/0.34+1.1 ms cpu, 3->3->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P

...

gc 1 @0.002s 4%: 0.012+0.78+0.005 ms clock, 0.098+0.49/0.58/0.32+0.040 ms cpu, 4->6->5 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
gc 2 @0.015s 2%: 0.016+1.3+0.034 ms clock, 0.12+0.022/1.1/0.90+0.27 ms cpu, 9->9->7 MB, 10 MB goal, 0 MB stacks, 0 MB globals, 8 P

输出结果说明

名称描述
gcGC 次数编号,每次 GC 时递增
@#s距离程序开始执行的时间
#%GC 执行占用的时间百分比
#msGC 使用的时间
#MBGC 开始前,结束时,当前正在被使用堆内存的大小
MB goal下一次触发 GC 的堆大小
MB stacks估计扫描栈大小
MB global可扫描的全局大小
#PP 的数量

下面以最后一行输出为例进行说明:

gc 2 @0.015s 2%: 0.016+1.3+0.034 ms clock, 0.12+0.022/1.1/0.90+0.27 ms cpu, 9->9->7 MB, 10 MB goal, 0 MB stacks, 0 MB globals, 8 P
名称描述
gc 17GC 编号为 2
@0.015s程序已经执行了 0.015s
2%GC 执行占用的时间为 1%
0.016+1.3+0.034 ms clockGC 使用时间,分别为 STW 清扫的时间 + 并发标记和扫描的时间 + STW 标记的时间
0.12+0.022/1.1/0.90+0.27 ms cpuGC 占用 CPU 时间
9->9->7 MBGC 开始前堆内存 9 M, 结束时堆内存 9 M,当前正在被使用堆内存 7 M
10 MB goal下一次触发 GC 的堆大小为 10M
8 PP 的数量为 8 个

输出调度完整信息

执行命令

$ GODEBUG=scheddetail=1,schedtrace=1000 go run main.go

# 输出如下
SCHED 0ms: gomaxprocs=8 idleprocs=6 threads=6 spinningthreads=1 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=1 schedtick=1 syscalltick=0 m=0 runqsize=0 gfreecnt=0 timerslen=0
  P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
  
...

  P7: status=0 schedtick=0 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
  M5: p=2 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=true blocked=false lockedg=-1
  
...

  M0: p=0 curg=1 mallocing=0 throwing=0 preemptoff= locks=5 dying=0 spinning=false blocked=false lockedg=1
  G1: status=2(chan receive) m=0 lockedm=0
  
...

  G4: status=4(GC scavenge wait) m=-1 lockedm=-1

...

SCHED 1008ms: gomaxprocs=8 idleprocs=8 threads=14 spinningthreads=0 idlethreads=7 runqueue=0 gcwaiting=0 nmidlelocked=1 stopwait=0 sysmonwait=0
  P0: status=0 schedtick=262 syscalltick=826 m=-1 runqsize=0 gfreecnt=0 timerslen=0

...

  P7: status=0 schedtick=17 syscalltick=307 m=-1 runqsize=0 gfreecnt=3 timerslen=0
  M13: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1

...

  M0: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G4: status=4(sleep) m=-1 lockedm=-1
  G5: status=4(finalizer wait) m=-1 lockedm=-1
  G12: status=6() m=-1 lockedm=-1
  G22: status=6() m=-1 lockedm=-1
  G10: status=4(GC worker (idle)) m=-1 lockedm=-1

...

  G78: status=4(select) m=-1 lockedm=10
  G146: status=4(chan receive) m=-1 lockedm=-1

输出结果说明

P 的相关输出说明,以下面这行输出为例:

P0: status=1 schedtick=1 syscalltick=0 m=0 runqsize=0 gfreecnt=0 timerslen=0
名称描述
P0编号
status状态
schedtick调度次数
syscalltick系统调用次数
m关联的 M
runqsize运行队列中 G 的数量
gfreecnt可用的 G 的数量
timerslen关联的定时器数量

P 的状态列表

const (
 // 处理器没有在执行代码或者调度,位于空闲列表或者被可以改变其状态的结构持有
 _Pidle = iota
 
 // 处理器被线程 M 持有,并且正在执行代码或者调度
 _Prunning
 
 // 处理器没有在执行代码,线程陷入系统调用
 _Psyscall
 
 // 处理器被线程 M 持有,由于 GC 被停止
 _Pgcstop
 
 // 处理器不再被使用
 _Pdead
)

M 的相关输出说明,以下面这行输出为例:

M0: p=0 curg=1 mallocing=0 throwing=0 preemptoff= locks=5 dying=0 spinning=false blocked=false lockedg=1
名称描述
M0编号
p关联的 P
curg当前运行的 G
mallocing是否正在分配内存
throwing是否抛出异常
preemptoff是否和当前运行的 G 绑定
locks
dying销毁状态
spinning是否正在自旋
blocked是否阻塞

G 的相关输出说明,以下面这行输出为例:

G1: status=2(chan receive) m=0 lockedm=0
名称描述
G1编号
status状态
m关联的 M

G 的状态列表

const (
 // goroutine 刚被分配并且还没有被初始化
    _Gidle = iota // 0

 // goroutine 处于运行队列中,没有在执行代码,没有栈的所有权
 _Grunnable // 1

 // goroutine 可以执行代码并且拥有有栈的所有权,M 和 P 已经设置并且有效
 _Grunning // 2

 // goroutine 正在执行系统调用,没有在执行代码,拥有栈的所有权但是不在运行队列中,此外,M 已经设置
 _Gsyscall // 3

 // goroutine 处于阻塞中,没有在执行代码并且不在运行队列中,但是可能存在于 Channel 的等待队列上
 _Gwaiting // 4

 // 没有使用这个状态,但是被硬编码到了 gbd 脚本中
 _Gmoribund_unused // 5

 // goroutine 没有被使用 (可能已经退出或刚刚初始化),没有在执行代码,可能存在分配的栈
 _Gdead // 6

 // 没有使用这个状态
 _Genqueue_unused // 7

 // goroutine 的栈正在被移动,没有在执行代码并且不在运行队列中
 _Gcopystack // 8

 // goroutine 由于抢占而阻塞,等待唤醒
 _Gpreempted // 9

 // GC 正在扫描栈空间,没有在执行代码,可以与上述其他状态同时存在
 _Gscan          = 0x1000
)

*声明:本文于网络整理,如来源信息有误或侵犯权益,请联系我删除或授权事宜。