How to profile memory usage in Golang

[목차]

1. 프로파일링 개요
2. 프로파일링 프로파일링 테스트 케이스 및 방법
3. 프로파일링 결과 요약
4. 시험 케이스별 프로파일링 결과 Snapshot
5. 프로파일링 분석 결과
6. 프로파일링 분석 결론 및 계획

---

1. 프로파일링 개요

• CB-Spider가 메모리를 과하게 사용한다는 리포트가 있었음
  • https://github.com/cloud-barista/cb-spider/issues/336
• CB-Spider의 주요 Operation들과 Memory를 가장 많이 사용하는 Operation에 대하여
     Test Case를 정의하고 Memory Leak 위주의 분석을 실행함.
• 대상 CB-Spider Version: v0.4.0-5-ga6b2ae9
• Go Profiling 방법 Reference
  • Go Package pprof
  • Profiling Go, Mark McDonnell, 2017.10.31.
  • Investigate memory leaks in Go, 2019.04.11.

2. 프로파일링 테스트 케이스 및 방법

• 프로파일링을 위한 pprof 코드 적용 필요

  • 적용 대상 소스: cb-spider/api-runtime/apiserver.go

  • 적용 코드 에시

     11 import (
          ... 생략
     24
     25         ///////////////// for profiling
     26         "log"
     27         "net/http"
     28         _ "net/http/pprof"
     29 )
     30
     31 func main() {
     32         ///////////////// for profiling
     33         go func() {
     34                 log.Println(http.ListenAndServe("1.2.3.4:8282", nil))
     35         }()
     36         wg := new(sync.WaitGroup)
     37         wg.Add(1)
     38         ///////////////// for profiling
     39
     40         rootCmd := NewRootCmd()
     41         if err := rootCmd.Execute(); err != nil {
     42                 fmt.Printf("cb-spider terminated with error: %v\n", err)
     43         }
     44         ///////////////// for profiling
     45         wg.Wait()
     46 }
          ... 이하 생략

• 준비 환경
  • 본 시험 환경: Ubuntu 18.04, go 1.16.5
  • Graph 출력 지원 도구 dot, gv 설치

    sudo apt-get install -y graphviz gv
    

• 프로파일링 절차
  • pprof를 적용한 CB-Spider 서버 가동
  • Test Case 실행으로 서버 메모리 상태 변화 유도
  • Browser 이용한 메모리 사용 현황 참고
    • http://1.2.3.4:8282/debug/pprof/
  • 메모리 현황 snapshot 이미지 뽑는 방법

    go tool pprof -png http://1.2.3.4:8282/debug/pprof/heap > data.png
    

• 프로파일링 테스트 케이스

  • [1] Spider Server start 후 측정
  • [2] AWS:VPC/Subnet, SecurityGroup, KeyPair 및 VM 1개 생성,
       Azure:VPC/Subnet, SecurityGroup, KeyPair 및 VM 1개 생성 후 측정
  • [3] AWS:ListImage 실행 후 측정
  • [4] Azure:ListImage 실행 후 측정
  • [5] Azure:ListImage 실행 후 측정
  • [6] Azure:ListImage 실행 후 측정
  • [7] 모든 자원을 삭제 후 측정
  • [8] drop caches 후 측정
  • [9] Spider Server stop 후 측정

  ※ [2], [7]: CB-Spider REST API(Echo) 활용
  ※ [3] ~ [6]: CB-Spider Go API(gRPC) 활용
  ※ 위와 같은 순서로 시험 케이스 실행시 마다 메모리 사용 현황 프로파일링

3. 프로파일링 결과 요약

	[1]	[2]	[3]	[4]	[5]	[6]	[7]	[8]
Mem Usages	11.7MB	13.416MB	63MB	37MB	13MB	38MB	13.8MB	13.8MB
Profile	Count	Count	Count	Count	Count	Count	Count	Count
allocs	41	41	1532	2236	2469	2596	2614	2614
block	0	0	0	0	0	0	0	0
cmdline	0	0	0	0	0	0	0	0
goroutine	12	12	17	15	11	16	9	10
heap	41	41	1532	2236	2469	2596	2614	2614
mutex	0	0	0	0	0	0	0	0
profile	0	0	0	0	0	0	0	0
threadcreate	20	20	20	20	20	20	20	20
trace	0	0	0	0	0	0	0	0

Profile Description:

• allocs: A sampling of all past memory allocations block: Stack traces that led to blocking on synchronization primitives
• cmdline: The command line invocation of the current program
• goroutine: Stack traces of all current goroutines
• heap: A sampling of memory allocations of live objects. You can specify the gc GET parameter to run GC before taking the heap sample.
• mutex: Stack traces of holders of contended mutexes
• profile: CPU profile. You can specify the duration in the seconds GET parameter. After you get the profile file, use the go tool pprof command to investigate the profile.
• threadcreate: Stack traces that led to the creation of new OS threads
• trace: A trace of execution of the current program. You can specify the duration in the seconds GET parameter. After you get the trace file, use the go tool trace command to investigate the trace.

4. 시험 케이스별 프로파일링 결과 Snapshot

• [1] Spider Server start 후 측정
  

• [2] AWS:VPC/Subnet, SecurityGroup, KeyPair 및 VM 1개 생성,
     Azure:VPC/Subnet, SecurityGroup, KeyPair 및 VM 1개 생성 후 측정
  

• [3] AWS:ListImage 실행 후 측정
  

• [4] Azure:ListImage 실행 후 측정
  

• [5] Azure:ListImage 실행 후 측정
  

• [6] Azure:ListImage 실행 후 측정
  

• [7] 모든 자원을 삭제 후 측정
  

• [8] drop caches 후 측정

  • [1] ~ [7] 동안 시스템 메모리 변화: 모든 시험 동안 GB 단위의 메모리 변화는 없음, 커널 파일 캐시나 버퍼로 이미 26GB가 사용중이며, 현재 시험과는 직접적인 영향은 없음.
    

    

  • 이를 확인하기 위해 cache를 drop 시킨 후 다시 측정 해봄.
    

    • ※ drop caches 후 cache는 반환 되고, Spider 프로세스는 GC 등의 변화 없이 그대로 13.8MB가 유지됨(아래 프로파일링 snapshot 참고).

    

  • 프로파일링 snapshot은 다음과 같음
    

• [9] Spider Server stop 후 측정

  • Spider 종료시 profile 서버 함께 종료로 프로파일링 측정 불가

  • Spider Server 종류 전-후 메모리 차이: 49MB
    

    

5. 프로파일링 분석 결과

• 메모리를 가장 많이(63MB) 사용하는 [3] 시나리오 현황(아래 그림, [3] 프로파일링 Snapshot 참고)이 아래와 같이 AdminWeb의 ImageList 웹서비스에서 소모되고 있음. (Image 목록: 9,465개)
• [3] 시나리오 수행 이후 ImageList 관련 사용했던 50MB 메모리 체인이 정상적으로 사라짐.([4]-[8] 프로파일링 snapshot 참고)

※ 참고: AWS:Oregon Region의 Image 목록 출력 후 서버 메모리 사용 상태

   (Operation 실행 후 결과이기도 하고, GC 영향으로 최고점의 메모리 사용 현황은 아닐 수 있음)

※ 관련 정보: Image 목록 9,465개 ==> HTML source 크기만: 10.4MB

   => 10.4MB 데이터 규모에 50MB 활용은 개선 포인트는 있겠지만, GB 단위 이하이므로 현재는 Pass

    ... 중간 생략

6. 프로파일링 분석 결론 및 계획

• 가장 메모리를 많이 활용하는 시나리오로 재현을 시도했지만, Critical한 메모리 누수는 재현되지 않음.
  • 가능성은 희박하지만, 그간 기능 추가 및 개선에 의해 자연 해결 되었을 수도...
• 시기상 기능 개발/개선 우선 추진, 추가 분석 진행하지 않고 마무리함.
• 향후 연관 이슈 발생시 추가 상세 분석 및 개선 추진, 또는, 안정화 시점에 필요시 재분석

※ 참고: Go GC(Garbage Collector) 정책에 의해 메모리 상태는 유동적일 수 있으며,
이로 인하여 [1] ~ [8] 시험 후 snapshot이 각 시험 케이스의 서버 메모리 상태를 대표할 수는 없음