How to profile memory usage in Golang - cloud-barista/cb-spider GitHub Wiki

[목차]

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

1. 프로파일링 개요

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 이용한 메모리 사용 현황 참고
    • 메모리 현황 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 후 측정

image

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

image

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

image

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

image

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

image

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

image

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

image

  • [8] drop caches 후 측정

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

      image

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

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

      image

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

  • [9] Spider Server stop 후 측정

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

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

      image

5. 프로파일링 분석 결과

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

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

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

image

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

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

image

    ... 중간 생략

image

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

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

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