Golang环境变量之GODEBUG

GODEBUGruntime

allocfreetrace

allocfreetrace = 1

clobberfree

clobberfree=1

cgocheck

cgo相关。

cgocheck=0

efence

efence=1

gccheckmark

GC相关。

gccheckmark=1

gcpacertrace

GC相关。

gcpacertrace=1

gcshrinkstackoff

GC相关。

gcshrinkstackoff=1可

gcstoptheworld

GC 相关。

gcstoptheworld=1gcstoptheworld=2

gctrace

GC 相关。

gctrade=1

forcedGODEBUG=gotrace=1 go run main.go

输出字段意义:
gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # P
where the fields are as follows:
gc # the GC number, incremented at each GC
@#s time in seconds since program start
#% percentage of time spent in GC since program start
#+...+# wall-clock/CPU times for the phases of the GC
#->#-># MB heap size at GC start, at GC end, and live heap
# MB goal goal heap size
# P number of processors used
The phases are stop-the-world (STW) sweep termination, concurrent
mark and scan, and STW mark termination. The CPU times
for mark/scan are broken down in to assist time (GC performed in
line with allocation), background GC time, and idle GC time.
If the line ends with "(forced)", this GC was forced by a
runtime.GC() call.

➜  gotest GODEBUG=gctrace=1 go run main.go
gc 1 @0.115s 0%: 0.067+0.92+0.003 ms clock, 0.26+0.41/0.78/0.011+0.015 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
gc 2 @0.194s 0%: 0.056+1.5+0.003 ms clock, 0.22+1.3/0.27/1.6+0.012 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
gc 3 @0.303s 0%: 0.24+1.5+0.004 ms clock, 0.98+0.20/0.32/1.5+0.016 ms cpu, 4->4->0 MB, 5 MB goal, 4 P
gc 4 @0.344s 0%: 0.12+0.45+0.003 ms clock, 0.51+0/0.41/0.81+0.012 ms cpu, 4->4->0 MB, 5 MB goal, 4 P

字段解释

垃圾回收信息

gc 1 @0.115s 0%: 0.018+1.3+0.076 ms clock, 0.054+0.35/1.0/3.0+0.23 ms cpu, 4->4->3 MB, 5 MB goal, 4 P`。

1@0.115s0%0.067+0.92+0.003 ms clock0.26+0.41/0.78/0.011+0.015 ms cpu4->4->0 MB5 MB goal4 P

scvg0: inuse: 426, idle: 0, sys: 427, released: 0, consumed: 427 (MB)

42604270427

madvdontneed

madvdontneed=1MADV_DONTNEEDMADV_FREE

memprofilerate

memprofilerate=Xruntime.MemProfileRate0MemProfileRate

invalidptr

// TODO

sbrk

sbrk=1碎片回收器

scavenge

scavenge=1heap scavenger

scavtrace

//TODO

scheddetail

调度相关。

schedtrace=Xscheddetail=1

package main

import "sync"

func main() {
   wg := sync.WaitGroup{}
   wg.Add(10)
   for i := 0; i < 10; i++ {
       go func(wg *sync.WaitGroup) {
           var counter int
           for i := 0; i < 1e10; i++ {
               counter++
           }
           wg.Done()
       }(&wg)
   }

   wg.Wait()
}

输出结果

➜  gotest GODEBUG=schedtrace=1000,scheddetail=1000 go run main.go
SCHED 0ms: gomaxprocs=4 idleprocs=2 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
  P2: status=1 schedtick=0 syscalltick=0 m=5 runqsize=0 gfreecnt=0 timerslen=0
  P3: 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
  M4: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=2 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=0 curg=1 mallocing=0 throwing=0 preemptoff= locks=3 dying=0 spinning=false blocked=false lockedg=1
  G1: status=2(chan receive) m=0 lockedm=0
  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(GC scavenge wait) m=-1 lockedm=-1
SCHED 0ms: gomaxprocs=4 idleprocs=1 threads=5 spinningthreads=1 idlethreads=0 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=1 schedtick=0 syscalltick=0 m=4 runqsize=1 gfreecnt=0 timerslen=0
  P1: status=1 schedtick=0 syscalltick=0 m=2 runqsize=0 gfreecnt=0 timerslen=0
  P2: status=0 schedtick=0 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
  P3: status=0 schedtick=0 syscalltick=0 m=-1 runqsize=0 gfreecnt=0 timerslen=0
  M4: p=0 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1

输出的内容比较的多，每行的信息属于谁只要看首列字母即可，如果是G开头的话，则是表示的是 GoRoutine, G0、G1、GN后面的数字表示是G的编号，是唯一的。如果是P的话，则就是处理器相关的信息，当然M就是线程了，每种资源都有多个，他们之间状态是来回变化的，由于阻塞或调度的原因。SCHED 则表示当前的调度信息。

statusschedticksyscalltickmrunqsize

P相关字段

statusschedticksyscalltickmrunqsizegfreecnt

M相关字段

pcurgmallocingthrowingpreemptofflocksdyingspinningblockedlockedg

G相关字段

statusmlockedm

schedtrace

调度相关。

schedtrade=X

package main

import "sync"

func main() {
    wg := sync.WaitGroup{}
    wg.Add(10)
    for i := 0; i < 10; i++ {
        go func(wg *sync.WaitGroup) {
            var counter int
            for i := 0; i < 1e10; i++ {
                counter++
            }
            wg.Done()
        }(&wg)
    }

    wg.Wait()
}

输出结果

➜  gotest GODEBUG=schedtrace=1000 go run main.go
SCHED 0ms: gomaxprocs=4 idleprocs=2 threads=4 spinningthreads=1 idlethreads=0 runqueue=0 [1 0 0 0]
SCHED 1ms: gomaxprocs=4 idleprocs=2 threads=7 spinningthreads=1 idlethreads=2 runqueue=0 [0 0 0 0]
SCHED 3ms: gomaxprocs=4 idleprocs=2 threads=7 spinningthreads=1 idlethreads=2 runqueue=0 [0 0 0 0]
SCHED 10ms: gomaxprocs=4 idleprocs=1 threads=7 spinningthreads=1 idlethreads=1 runqueue=0 [7 7 0 0]
SCHED 15ms: gomaxprocs=4 idleprocs=0 threads=7 spinningthreads=1 idlethreads=0 runqueue=0 [3 1 3 0]
SCHED 18ms: gomaxprocs=4 idleprocs=0 threads=7 spinningthreads=0 idlethreads=0 runqueue=0 [1 1 3 1]
SCHED 22ms: gomaxprocs=4 idleprocs=0 threads=8 spinningthreads=0 idlethreads=0 runqueue=1 [1 1 3 1]
SCHED 24ms: gomaxprocs=4 idleprocs=0 threads=8 spinningthreads=0 idlethreads=1 runqueue=0 [0 0 0 0]
SCHED 25ms: gomaxprocs=4 idleprocs=0 threads=8 spinningthreads=0 idlethreads=1 runqueue=0 [0 0 0 0]
SCHED 29ms: gomaxprocs=4 idleprocs=0 threads=8 spinningthreads=1 idlethreads=0 runqueue=0 [0 6 0 0]
SCHED 30ms: gomaxprocs=4 idleprocs=1 threads=8 spinningthreads=1 idlethreads=1 runqueue=0 [0 0 0 0]
......

我们这时设置的是 schedtrace=1000,即1秒输出一次，

SCHEDschedtracegomaxprocsidleprocsthreads：OSspinningthreadsidlethreadsrunqueue

scheddetailGODEBUG=schedtrace=1000,scheddetail=1 go run main.go

推荐使用pprof查看，目前这种方式不是太友好。

tracebackancestors

//TODO

asyncpreemptoff

异步抢占

gotraceschedtracescheddetail

netnet/httpcrypto/tls

Golang环境变量之GODEBUG

allocfreetrace

clobberfree

cgocheck

efence

gccheckmark

gcpacertrace

gcshrinkstackoff

gcstoptheworld

gctrace

madvdontneed

memprofilerate

invalidptr

sbrk

scavenge

scavtrace

scheddetail

schedtrace

tracebackancestors

asyncpreemptoff

参考