github.com/songzhibin97/gkit@v1.2.13/watching/example/gcheap/README.md (about) 1 2 ## How to test 3 4 1. change to the current gcheap directory 5 ``` 6 cd /path/to/gcheap/ 7 ``` 8 9 2. compile 10 ``` 11 go build gcheap.go 12 ``` 13 14 3. start the sample http server with the gctrace enabled. 15 ``` 16 GODEBUG=gctrace=1 ./gcheap 17 ``` 18 19 4. start the rand allocation case 20 ``` 21 ./rand.sh 22 ``` 23 24 the `/rand` api will allocation some memory and will be recycled soon, 25 the internal `heapMarked` will stay about 10 MB, and the GC Goal will stay about 21MB. 26 27 we can see the following gctrace log from stdout: 28 ``` 29 gc 28 @11.666s 0%: 0.17+0.19+0.017 ms clock, 2.0+0.085/0.19/0.13+0.20 ms cpu, 20->20->10 MB, 21 MB goal, 12 P 30 gc 29 @12.121s 0%: 0.065+0.21+0.015 ms clock, 0.78+0.11/0.23/0.13+0.18 ms cpu, 20->20->10 MB, 21 MB goal, 12 P 31 ``` 32 33 Also, we can see the following Watching log from /tmp/Watching.log: 34 ``` 35 [Watching] NODUMP GCHeap, config_min : 10, config_diff : 20, config_abs : 40, config_max : 0, previous : [10 10 10 10 10 10 10 10 10 10], current: 10 36 ``` 37 38 Everything works well now. 39 40 5. memory spike 41 ```bash 42 curl http://localhost:10024/spike 43 ``` 44 45 The `/spike` API will allocate 10 MB memory and keep for a while. 46 47 We can see the GC goal increased from the gctrace log: 48 ``` 49 gc 432 @191.430s 0%: 0.14+0.40+0.004 ms clock, 1.7+0.26/0.41/0.52+0.051 ms cpu, 21->22->19 MB, 22 MB goal, 12 P 50 gc 433 @192.079s 0%: 0.042+0.22+0.002 ms clock, 0.51+0.097/0.38/0.21+0.024 ms cpu, 37->37->10 MB, 38 MB goal, 12 P 51 ``` 52 53 And we see that we got two profiles from Watching log: 54 ``` 55 [2022-02-09 14:48:23.103][Watching] pprof GCHeap, config_min : 10, config_diff : 20, config_abs : 40, config_max : 0, previous : [10 10 10 10 10 10 10 10 10 19], current: 19 56 [2022-02-09 14:48:23.751][Watching] pprof GCHeap, config_min : 10, config_diff : 20, config_abs : 40, config_max : 0, previous : [10 10 10 10 10 10 10 10 10 19], current: 10 57 ``` 58 59 6. generate flamegraph 60 61 we will know what cause the GC goal increased exactly by using the following command. 62 (we got the profile name by timestamp that from Watching log) 63 ``` 64 go tool pprof -http=:8000 -base GCHeap.20220209144823.103.bin GCHeap.20220209144823.751.bin 65 ``` 66 67 It shows the reason for memory spike clearly.