這是一個建立於 的文章,其中的資訊可能已經有所發展或是發生改變。
如何開啟列印gc資訊
只要在程式執行之前加上環境變數GODEBUG gctrace =1
,如:
GODEBUG gctrace =1 ./xxxx.exe
or GODEBUG gctrace =1 go run main.go
程式將會顯示gc資訊,如下
gc 1 @2.104s 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 Pgc 2 @2.241s 0%: 0.019+2.4+0.077 ms clock, 0.079+0/2.4/6.4+0.30 ms cpu, 5->6->5 MB, 6 MB goal, 4 Pgc 3 @2.510s 0%: 0.011+3.2+0.063 ms clock, 0.047+0.10/2.9/9.0+0.25 ms cpu, 11->11->10 MB, 12 MB goal, 4 Pgc 4 @3.021s 0%: 0.013+6.6+0.076 ms clock, 0.053+0.34/6.2/18+0.30 ms cpu, 21->21->20 MB, 22 MB goal, 4 Pgc 5 @3.725s 0%: 0.015+15+0.079 ms clock, 0.062+0.35/15/45+0.31 ms cpu, 40->40->39 MB, 41 MB goal, 4 Pgc 6 @4.741s 0%: 0.008+35+0.17 ms clock, 0.035+0.19/35/100+0.70 ms cpu, 76->76->75 MB, 78 MB goal, 4 Pgc 7 @6.688s 0%: 0.020+117+0.34 ms clock, 0.082+11/117/330+1.3 ms cpu, 147->148->146 MB, 151 MB goal, 4 Pgc 8 @68.645s 0%: 0.019+146+0.30 ms clock, 0.078+0.006/146/407+1.2 ms cpu, 285->285->248 MB, 292 MB goal, 4 Pscvg0: inuse: 426, idle: 0, sys: 427, released: 0, consumed: 427 (MB)gc 9 @175.448s 0%: 0.030+60+0.12 ms clock, 0.12+0.013/60/177+0.51 ms cpu, 484->484->248 MB, 496 MB goal, 4 Pgc 10 @236.621s 0%: 0.006+59+0.11 ms clock, 0.025+0/59/173+0.47 ms cpu, 484->484->248 MB, 496 MB goal, 4 Pgc 11 @285.967s 0%: 0.027+57+0.22 ms clock, 0.11+0/57/163+0.89 ms cpu, 484->484->248 MB, 496 MB goal, 4 Pscvg1: inuse: 331, idle: 175, sys: 507, released: 0, consumed: 507 (MB)gc 12 @333.817s 0%: 0.009+52+0.18 ms clock, 0.036+0/52/155+0.72 ms cpu, 484->484->248 MB, 496 MB goal, 4 P
gc資訊的含義
查看官方的runtime說明:
gctrace: setting gctrace=1 causes the garbage collector to emit a single line to standarderror at each collection, summarizing the amount of memory collected and thelength of the pause. Setting gctrace=2 emits the same summary but alsorepeats each collection. The format of this line is subject to change.Currently, it is:gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # Pwhere 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 usedThe phases are stop-the-world (STW) sweep termination, concurrentmark and scan, and STW mark termination. The CPU timesfor mark/scan are broken down in to assist time (GC performed inline with allocation), background GC time, and idle GC time.If the line ends with "(forced)", this GC was forced by aruntime.GC() call and all phases are STW.Setting gctrace to any value > 0 also causes the garbage collectorto emit a summary when memory is released back to the system.This process of returning memory to the system is called scavenging.The format of this summary is subject to change.Currently it is:scvg#: # MB released printed only if non-zeroscvg#: inuse: # idle: # sys: # released: # consumed: # (MB)where the fields are as follows:scvg# the scavenge cycle number, incremented at each scavengeinuse: # MB used or partially used spansidle: # MB spans pending scavengingsys: # MB mapped from the systemreleased: # MB released to the systemconsumed: # MB allocated from the system
記憶體回收資訊
gc 1 @2.104s 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
表示第一次執行
@2.104s
表示程式執行的總時間
0%
記憶體回收時間佔用的百分比,(不知道和誰比?難道是和上面的程式執行總時間,這樣比較感覺沒意義)
0.018+1.3+0.076 ms clock
記憶體回收的時間,分別為STW(stop-the-world)清掃的時間, 並發標記和掃描的時間,STW標記的時間
0.054+0.35/1.0/3.0+0.23 ms cpu
記憶體回收佔用cpu時間
4->4->3 MB
堆的大小,gc後堆的大小,存活堆的大小
5 MB goal
整體堆的大小
4 P
使用的處理器數量
系統記憶體回收資訊,這個很直白,看單詞就知道大概意思了
scvg0: inuse: 426, idle: 0, sys: 427, released: 0, consumed: 427 (MB)
426
使用多少M記憶體
0
剩下要清除的記憶體
427
系統映射的記憶體
0
釋放的系統記憶體
427
申請的系統記憶體