golang 打印gc信息

启动命令

GODEBUG='gctrace=1' nohup ./app &

日志信息

---

[GIN-debug] Listening and serving HTTP on :8000
GC forced
gc 2 @123.080s 0%: 0.052+7.6+0.002 ms clock, 3->3->2 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
GC forced
gc 3 @243.101s 0%: 0.091+0.40+0.002 ms clock, 0.72+0/0.70/1.7+0.018 ms cpu, 2->2->2 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 8 P
 

官方参数解释

Currently, it is:
    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 and all phases are STW.

gc 2： 第2次gc。

@123.080s： runtime启动到现在的时间。

0%：gc的标记工作（包括两次mark阶段的STW和并发标记）所用的CPU时间占总CPU的百分比。

0.052+7.6+0.002 ms clock：按顺序分成三部分，0.052表示mark阶段的STW时间（单P的）；7.6表示并发标记用的时间（所有P的）；0.002 表示markTermination阶段的STW时间（单P的）。

0.41+0/0.80/9.1+0.018 ms cpu：按顺序分成三部分，0.41表示整个进程在mark阶段STW停顿时间(0.052* 8)；0/0.80/9.1有三块信息，0是mutator assists占用的时间，0.80是dedicated mark workers+fractional mark worker占用的时间，9.1是idle mark workers占用的时间。这三块时间加起来会接近7.6*8(P的个数)；0.018 ms表示整个进程在markTermination阶段STW停顿时间(0.018 * 8)。

3->3->2 MB：按顺序分成三部分，3表示开始mark阶段前的heap_live大小；3表示开始markTermination阶段前的heap_live大小；2表示被标记对象的大小。

4MB goal：表示下一次触发GC的内存占用阀值是4MB，等于2MB * 2

8 P：本次gc共有多少个P。