k8s pod goroutine

# k8s 환경에서 golang 서버를 pod 로 만들어 stress test(부하 테스트)를 했다.

# 부하 테스트 툴은 vegeta 를 사용

https://github.com/tsenart/vegeta

# 1개의 pod 를 운영하고 1000/1s 로 부하를 주면

echo "GET http://ysofman.test.com:9999/test" | vegeta attack -duration=10s -rate=1000/1s -timeout=500ms | tee results.bin | vegeta report

# 다음과 같이 17% 성공한다.

# 1000*0.17 = 170tps

Requests      [total, rate]            10000, 1000.05

Duration      [total, attack, wait]    10.151548026s, 9.999496s, 152.052026ms

Latencies     [mean, 50, 95, 99, max]  51.131863ms, 0s, 379.564354ms, 480.801383ms, 561.313466ms

Bytes In      [total, mean]            20482436, 2048.24

Bytes Out     [total, mean]            0, 0.00

Success       [ratio]                  17.42%

Status Codes  [code:count]             0:8258  200:1742

# 부하 테스트 중 해당 pod pprof 를 refresh 하면서 확인해 보면

# goroutine 수가 최대 50개 정도로 부하에 비해 많이 늘어 나지 않는다.

http://ysofman.test.com:9999/debug/pprof

# 그냥 로컬 환경으로 서버를 띄워 부하 테스트 하면 100%성공으로 1000tps 가 나온다.

# pprof 를 확인하면 goroutine 이 200 개 이상으로 늘어났다 줄어든다.

# 원인은 k9s deployment 설정에서 container resource 부분에

# pod가 있는 실제 node 의 리소스가 충분하면 pod 의 컨테이너가 사용할 수 있는 

# cpu 리소스가 100m 0.1core 이상 사용할 수 있도록 허용하고 (requests)

# 최대 cpu 리소스가 250m 0.25core 까지만 사용하도록 제한돼 있었다.(limits)

# 참고로

# requests 를 사용할 수 있는 node 에 스케줄링 된다.

# limits 를 넘어가면 OOM(Out Of Memory)에러와 함께 종료시킨다.

# https://kubernetes.io/docs/concepts/configuration/manage-resources-containers

# m은 milli 단위로 1000m = 1 = 1core 를 사용할 수 있다.

resources:

 limits:

   cpu: 250m

 requests:

   cpu: 100m

# goroutine 을 core 개수만큼 goroutine 을 동시에서 처리할 수 있는데

# runtime.NumCPU() 가 8 이고,

# runtime.GOMAXPROCS(8) 로 8개 코어(프로세서)를 사용할 수 있도록 설정해도

# k8s 차원에서 pod core 를 1/4core 로 제한해서

# 부하처리를 위한 goroutine 들이 pending 되어 대다수 응답이 타임아웃된다.

# cpu limits 를 8 로 늘리면 1000tps (100%성공률) 성능이 나온다.

golang pprof trace - request canceled

# golang client 에서 'request canceled' 로 커넥션자체가 안되는 경우가 발생한다.
# net/http/transport.go 에 다음과 같이 정의 되어 있다.
var errRequestCanceled = errors.New("net/http: request canceled")

# 찾아보면 위 에러가 발생할 수 있는 경우는 다음과 같다.
net/http/transport.go:2024 -> roundTrip() 에서 reqcanceler 를  replace 하다 실패하는 경우
net/http/transport.go:601 -> CancelRequest() 로 호출되는 경우

# 우선 프로그램 내부 상태 파악을 위해 네트워크 타임아웃 프로파일링을 해보자.
# 참고 https://yoonbh2714.blogspot.com/2016/02/golang-pprof_47.html
# golang trace 2초 덤프를 2초 간격으로 100개 생성해본다.
#!/bin/bash
for cnt in {1..100}
do

    curTime=$(date +%H:%M:%S)
    sleep 
    curl 'http://localhost:9000/debug/pprof/trace?seconds=2' -o trace${cnt}-${curTime}.out
done

# 생성된 덤프파일을 하나씩 열어
go tool trace trace1-xx:xx:xx.out

# Goroutine analysis -> 네트워크를 사용하는 함수 선택하면 다음과 같이 해당 함수를 여러개의 고루틴들이 수행중이였음을 보여준다.
# 참고로 아래 캡쳐 화면중 빈 공간은 비공개 내용으로 삭제처리함


# 이중 timeout(>1000ms)을 넘는 루틴을 클릭해보면 다음과 같은 타임라인이 보이고
# 화살표로 보고 싶은 타임라인의 영역 드래그하면 아래 해당 영역에서 사용중인 함수리스트가 보인다.


# 문제가 되는 setRequestCancel 함수를 클릭 -> incoming flow go(link) 에서 스택을 확인할 수 있다.



# 위 스택을 보면 net/http/client.go:248 에서 다음과 같이 setRequest 를 호출하고 있고
stopTimer, didTimeout := setRequestCancel(req, rt, deadline)

# net/http/client.go:320 에서 다음과 같이 고루틴에서 timeOut 이 발생할 수 있다.
go func() {
    select {
    case <-initialReqCancel:
        doCancel()
        timer.Stop()
    case <-timer.C:
        timedOut.setTrue()
        doCancel()
    case <-stopTimerCh:
        timer.Stop()
    }
}()

# doCancel() -> CancelRequest() 가 호출된다.

golang pprof 사용하기

# golang 에서의 pprof 프로파일링 패키지를 사용해서 코드를 점검할 수 있다.
# 사용하기 위해서는 패키지와 웹리스너용 고루틴 하나 추가하면 된다.
// ysoftman
// pprof 사용 테스트
package main

import (
"fmt"
"log"
"net/http"
_ "net/http/pprof"
"time"
)

func main() {
go func() {
log.Println(http.ListenAndServe("localhost:6060", nil))
}()
for {
time.Sleep(100 * time.Millisecond)
fmt.Println("ysoftman")
}
select {}
}

# pprof.go init()에 이미 다음과 핸들러 들이 등록되 있어 별도로 등록하지 않아도 된다.

func init() {

http.Handle("/debug/pprof/", http.HandlerFunc(Index))

http.Handle("/debug/pprof/cmdline", http.HandlerFunc(Cmdline))

http.Handle("/debug/pprof/profile", http.HandlerFunc(Profile))

http.Handle("/debug/pprof/symbol", http.HandlerFunc(Symbol))

http.Handle("/debug/pprof/trace", http.HandlerFunc(Trace))

}

# 만약 별도 선언 후 /debug/pprof/trace 등 사용시 404 NOT FOUND 가 발생한다면

# 다음과 같이 pprof.Trace 등을 사용하도록 해야 한다.

r.HandleFunc("/pprof/cmdline", pprof.Cmdline)

r.HandleFunc("/pprof/symbol", pprof.Symbol)

r.HandleFunc("/pprof/profile", pprof.Profile)

r.HandleFunc("/pprof/trace", pprof.Trace)

...

# 이제 프로그램을 실행시키고 다음 url 로 접속하면 기본적으로
# block, goroutine, heap, threadcreate 등의 정보를 파악할 수 있다.
http://localhost:6060/debug/pprof/

# heap pprof 수행
# pprof 명령은 help 로 파악할 수 있다.
# -http=:9999 를 사용하면 웹(브라우저로 볼 수 있다.)
go tool pprof http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /Users/ysoftman/pprof/pprof.alloc_objects.alloc_space.inuse_objects.inuse_space.009.pb.gz
Type: inuse_space
Time: Apr 9, 2019 at 4:48pm (KST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 514.63kB, 100% of 514.63kB total
      flat  flat%   sum%        cum   cum%
  514.63kB   100%   100%   514.63kB   100%  math/rand.NewSource
         0     0%   100%   514.63kB   100%  math/rand.init.ializers
         0     0%   100%   514.63kB   100%  runtime.main
(pprof) exit

# 5초(디폴트30초)간 cpu 프로파일링
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=5
Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile?seconds=5
Please wait... (5s)
Saved profile in /Users/ysoftman/pprof/pprof.samples.cpu.004.pb.gz
Type: cpu
Time: Apr 9, 2019 at 4:55pm (KST)
Duration: 5s, Total samples = 0
No samples were found with the default sample value type.
Try "sample_index" command to analyze different sample values.
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) exit

# 위에서 저장된 프로파일링 파일을 다시 웹으로 볼 수 있다.
go tool pprof -http=:9999 /Users/ysoftman/pprof/pprof.samples.cpu.004.pb.gz

# 또는 go tool 을 이용해 콘솔에서 프로파일링할 수 있다.

# 5초동안 트레이스 덤프
curl 'http://localhost:6060/debug/pprof/trace?seconds=5' -o trace.out

# 트레이스 덤프 보기, http://127.0.0.1:xxxx 로 확인
go tool trace trace.out

# 힙 메모리 덤프

curl 'http://localhost:6060/debug/pprof/heap' -o heap.out

# 힙 메모리중 가장 많이 사용하 부분 보기

go tool pprof heap.out

(pprof) top

# golang 1.11 pprof 부터 flamegrpah 로 볼 수 있다.

# https://github.com/google/pprof/issues/166#issuecomment-415872987

go tool pprof -http=:8080 heap.out 으로 웹페이지 띄우고 view -> flame graph

# 참고
https://golang.org/pkg/net/http/pprof
https://golang.org/cmd/trace/