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.