サーバーサイドエンジニアの曽根田です。
前回は弊社のサービス開発の裏側を紹介させていただきました。
その中で goroutine のパフォーマンスについて、いくつかコメントをいただきました。
そこで本日は InfluxDB Grafana を使用し、golang標準パッケージexpvar からメトリクス情報を取得し、goroutine の数が増加した時の、メトリクスデータをグラフで可視化していきたいと思います。
※データー可視化ツールの Grafana については弊社のインフラエンジニアがPrometheusと組み合わせて監視環境を構築した例を紹介させていただいていいるので、興味のある方はみてください。
目的
goroutine の数が増えた時にパフォーマンスにどのような影響を与えるかの検証するのが今回の目的です。
このような検証を行おうと思った理由は以下です。
- 実際の運用の中で、goroutineがパフォーマンスに影響を与えている可能性があった為
- goroutineスケジューラー設計Document内のパフォーマンスについての記載が気になった為
検証環境
- EC2 t2.medium
- Amazon Linux AMI 2017.09
検証に用いたツール
- golang(1.9)
- InfluxDB(1.4.2)
- Grafana(4.6.3)
検証用のアプリケーション
※「検証用アプリケーションの準備」にコードが書いてあります。
-
fizzbazzの処理を行うアプリケーション(TEST Appliaction)
– fizzbassSequentialHandler(シーケンシャルに処理)
– fizzbassGotourineHandler(goroutineを使用して並列処理)
– expvarMetrics(expvarを使用してJSONフォーマットでメトリクスを公開するfunction) - TEST Applicationから取得したメトリクスをInfluxDBに保存するアプリケーション
検証用ツールの準備(InfluxDB/Grafana)
InfluxDB
https://docs.influxdata.com/influxdb/v0.9/introduction/installation/
$ sudo yum install https://repos.influxdata.com/rhel/7/x86_64/stable/influxdb-1.4.2.x86_64.rpm
$ sudo service influxdb start
$ influx
以下のような画面が表示されていればインストール完了です。
Grafana
http://docs.grafana.org/installation/rpm/
$ sudo yum install https://s3-us-west-2.amazonaws.com/grafana-releases/release/grafana-4.6.3-1.x86_64.rpm
$ service grafana-server start
xxx.xxx.xxx.xxx:3000(デフォルトがport3000)にアクセスすると以下の画面が表示されます。
※Grafanaの使用方法はここでは割愛させていただきます。
検証用アプリケーションの準備
TEST Appliaction(fizzbazz)
port 9999
- expvarのメトリクスを取得するハンドラーをルーティング(/debug/vars)
port 8080
- シーケンシャルにfizzbazzを処理するハンドラーをルーティング(/sequential)
- goroutineを使用し並列にfizzbazzを処理するハンドラーをルーティング(/goroutine)
※ expvarについて
https://golang.org/pkg/expvar/
※ 設定ポートは適宜変更してください。
package main
import (
"encoding/json"
"expvar"
"log"
"net/http"
"os"
"runtime"
"sync"
"time"
_ "github.com/go-sql-driver/mysql"
"github.com/shirou/gopsutil/process"
)
var PID int
var (
svMetrics = expvar.NewMap("sv")
Goroutines = new(expvar.Int)
CpuPercent = new(expvar.Float)
)
// データ収集
func runCollectData() chan<- bool {
fin := make(chan bool, 1)
ticker := time.Tick(time.Second * 1)
ticker4cpu := time.Tick(time.Second * 1)
go func() {
for {
select {
case <-fin:
return
case <-ticker:
Goroutines.Set(int64(runtime.NumGoroutine()))
case <-ticker4cpu:
CpuPercent.Set(getCpuPercent(PID))
}
}
}()
return fin
}
// CPU使用率の計算
func getCpuPercent(pid int) (percent float64) {
proc, err := process.NewProcess(int32(pid))
if err == nil {
}
percent, err = proc.Percent(time.Second * 4)
if err != nil {
return 0.0
}
return percent
}
// メトリクス取得
func expvarMetrics() {
PID = os.Getpid()
log.Println(PID)
svMetrics.Set("Goroutines", Goroutines)
svMetrics.Set("Cpu", CpuPercent)
_ = runCollectData()
go http.ListenAndServe(":9999", nil)
}
type FizzBazz struct {
Fizz int `json:"fizz"`
Bazz int `json:"Bazz"`
}
// FizzBazz
func fizzBazz(max int, fizzBazz *FizzBazz) {
for i := 0; i <= max; i++ {
fizz := i%3 == 0
buzz := i%5 == 0
switch {
case fizz && buzz:
fizzBazz.Fizz++
fizzBazz.Bazz++
case fizz && !buzz:
fizzBazz.Fizz++
case !fizz && buzz:
fizzBazz.Bazz++
default:
}
}
}
// GoroutineでFizzBazz
func fizzbassGotourineHandler(w http.ResponseWriter, r *http.Request) {
fizzbass := &FizzBazz{}
wg := &sync.WaitGroup{}
for i := 0; i < 1000; i++ {
wg.Add(1)
go func(i int) {
fizzBazz(i, fizzbass)
wg.Done()
}(i)
}
wg.Wait()
j, _ := json.Marshal(fizzbass)
w.WriteHeader(200)
w.Header().Set("Content-Type", "application/json; charset=utf-8")
w.Write(j)
}
// シーケンシャルにFizzBazz
func fizzbassSequentialHandler(w http.ResponseWriter, r *http.Request) {
fizzbass := &FizzBazz{}
for i := 0; i < 1000; i++ {
fizzBazz(i, fizzbass)
}
j, _ := json.Marshal(fizzbass)
w.WriteHeader(200)
w.Header().Set("Content-Type", "application/json; charset=utf-8")
w.Write(j)
}
func main() {
cpus := runtime.NumCPU()
log.Println(cpus)
expvarMetrics()
http.HandleFunc("/sequential", fizzbassSequentialHandler)
http.HandleFunc("/goroutine", fizzbassGotourineHandler)
http.ListenAndServe(":8080", nil)
}
TEST Applicationから取得したメトリクスをInfluxDBに保存
※コード内のxxx.xxx.xxx.xxx:9999の箇所はTEST Application内で設定したHTTPサーバに適宜変更してください
expvarのメトリクス項目については公式ドキュメントを参照してください。
https://golang.org/pkg/expvar/
package main
import (
"encoding/json"
"fmt"
"io/ioutil"
"log"
"net/http"
"time"
client "github.com/influxdata/influxdb/client/v2"
)
const (
db = "performance_test"
username = "root"
password = "root"
meas = "test_application"
)
type Point struct {
name string
tags map[string]string
fields map[string]interface{}
}
type MemstatsData struct {
Alloc int `json:"Alloc"`
TotalAlloc int `json:"TotalAlloc"`
Sys int `json:"Sys"`
Frees int `json:"Frees"`
HeapAlloc int `json:"HeapAlloc"`
HeapSys int `json:"HeapSys"`
HeapIdle int `json:"HeapIdle"`
HeapInuse int `json:"HeapInuse"`
HeapReleased int `json:"HeapReleased"`
HeapObjects int `json:"HeapObjects"`
StackInuse int `json:"StackInuse"`
StackSys int `json:"StackSys"`
MSpanInuse int `json:"MSpanInuse"`
MSpanSys int `json:"MSpanSys"`
MCacheInuse int `json:"MCacheInuse"`
MCacheSys int `json:"MCacheSys"`
BuckHashSys int `json:"BuckHashSys"`
GCSys int `json:"GCSys"`
OtherSys int `json:"OtherSys"`
NextGC int `json:"NextGC"`
LastGC int `json:"LastGC"`
GCCPUFraction float32 `json:"GCCPUFraction"`
NumGC int `json:"NumGC"`
}
type SVData struct {
CPU float32 `json:"Cpu"`
Goroutines int `json:"Goroutines"`
}
type ExpvarData struct {
Cmdline []string `json:"cmdline"`
Memstats MemstatsData
SV SVData
}
func createDatabase(c client.Client, cmd string) {
q := client.NewQuery(cmd, db, "")
if res, err := c.Query(q); err != nil && res.Error() == nil {
fmt.Errorf("createDatabase() error: %v: %s\n", res.Results, err)
}
}
func registMetricsData(c client.Client, p Point) {
bp, err := client.NewBatchPoints(client.BatchPointsConfig{
Database: db,
Precision: "",
})
if err != nil {
log.Fatal(err)
}
pt, err := client.NewPoint(p.name, p.tags, p.fields, time.Now())
if err != nil {
log.Fatal(err)
}
bp.AddPoint(pt)
if err := c.Write(bp); err != nil {
log.Fatal(err)
}
}
func main() {
for {
// Create a new HTTPClient
c, err := client.NewHTTPClient(client.HTTPConfig{
Addr: "http://localhost:8086",
Username: username,
Password: password,
})
if err != nil {
log.Fatal(err)
}
defer c.Close()
// create database if not exists
createDatabase(c, fmt.Sprintf("CREATE DATABASE %s", db))
url := "http://xxx.xxx.xxx.xxx:9999/debug/vars"
res, _ := http.Get(url)
defer res.Body.Close()
byteArr, _ := ioutil.ReadAll(res.Body)
var expvarData ExpvarData
err = json.Unmarshal(byteArr, &expvarData)
if err != nil {
fmt.Println(err)
}
fmt.Println(expvarData)
// insert data
p := Point{
name: meas,
tags: map[string]string{
"application": "test",
},
fields: map[string]interface{}{
"CPU": expvarData.SV.CPU,
"Goroutine": expvarData.SV.Goroutines,
"Alloc": expvarData.Memstats.Alloc,
"TotalAlloc": expvarData.Memstats.TotalAlloc,
"Sys": expvarData.Memstats.Sys,
"Frees": expvarData.Memstats.Frees,
"HeapAlloc": expvarData.Memstats.HeapAlloc,
"HeapIdle": expvarData.Memstats.HeapIdle,
"HeapInuse": expvarData.Memstats.HeapInuse,
"HeapSys": expvarData.Memstats.HeapSys,
"HeapReleased": expvarData.Memstats.HeapReleased,
"HeapObjects": expvarData.Memstats.HeapObjects,
"StackInuse": expvarData.Memstats.StackInuse,
"StackSys": expvarData.Memstats.StackSys,
"MSpanInuse": expvarData.Memstats.MSpanInuse,
"MSpanSys": expvarData.Memstats.MSpanSys,
"MCacheInuse": expvarData.Memstats.MCacheInuse,
"MCacheSys": expvarData.Memstats.MCacheSys,
"BuckHashSys": expvarData.Memstats.BuckHashSys,
"GCSys": expvarData.Memstats.GCSys,
"NextGC": expvarData.Memstats.NextGC,
"LastGC": expvarData.Memstats.LastGC,
"NumGC": expvarData.Memstats.NumGC,
"GCCPUFraction": expvarData.Memstats.GCCPUFraction,
},
}
registMetricsData(c, p)
// 0.5秒間隔
time.Sleep(500 * time.Millisecond)
}
}
メトリクスの収集と可視化
ツール、テスト用サンプルアプリケーション、メトリクス取集用アプリケーションの準備を整えた後、テスト用サンプルアプリケーション、メトリクス取集用アプリケーションを起動させてください。
次にベンチマークツールでテスト用サンプルアプリケーションに負荷をかけていきます。
今回はweighttpというツールを使用しました。
https://github.com/lighttpd/weighttp
それでは順番に負荷をかけていきます。
それぞれ並列数100で合計1000リクエストをループで実行していきます。
シーケンシャルにfizzbazz
#!/bin/sh
for i in {0..1000}
do
weighttp -k -c 100 -n 1000 http://xxx.xxx.xxx.xxx:8080/goroutine;
sleep 1
done
並列でfizzbazz
#!/bin/sh
for i in {0..1000}
do
weighttp -k -c 100 -n 1000 http://xxx.xxx.xxx.xxx:8080/sequential;
sleep 1
done
ある程度メトリクスのデータを収集し、Grafanaからメトリクスを確認します。
※ 収集したデータはInfluxDBから直接確認できます。
※ GrafanaでのDashBoard設定/グラフ作成方法については今回は割愛させていただきます。
以下がexpvarのメトリクスデータをGrafanaで可視化した例です。
メトリクスデータから結果を読み解く
goroutine数とCPU負荷
赤枠 → goroutine使用(並列)
青枠 → goroutine無し(シーケンシャル)
CPU使用率
goroutine数
上記のグラフを見てみると、
赤枠のメトリクスデータの方がほぼ常に2コアのCPUを100%使用している状態で張り付いています。
一方で青枠のメトリクスデータは100%に達している時もあるものの平均して80%〜90%に収まっているのがわかります。
goroutine数と使用メモリ
スタック
ヒープ
goroutine数
メモリの使用量も赤枠と青枠と大きくグラフの形が違うのがわかります。
個人的な見解
実際にgoroutine の数が増加した時の、メトリクスデータをグラフで可視化していました。
Javaなどのスレッドと比べてコストがかなり低いと言われながらも、 大量にgoroutineを生成するとそれなりのコストがかかってしまうというのが個人的な見解です。
webサーバ(Apache, Nginx等)やアプリケーションサーバを設置して、同時リクエスト制御を任せてることが多いと思います。
これらが、並列で稼働している環境下でのgoroutineをむやみに生成することは極力避けたほうが無難です。
また実効速度に関しても、上記のコードではgoroutineを使った場合とそうでない場合で差はありませんでした。
(高負荷時には、goroutineを使用していると速度が遅くなる傾向がみられます。)
最後に
今回はgolangアプリケーションのメトリクスをGrafanaを使用し、expvarのメトリクスをグラフ化してみました。
実際に動いている本番のアプリケーションに投入することで、AWS Cloud Watchでは取れないメトリクスを監視することができるようになります。
実際のパフォーマンス改善など行うときは、ざっくりとした異常値をexpvarのメトリクスで検知し、その後pprofなどで細かく処理を追っていくという手順になるかと思います。
今回も最後までブログに目を通していただきありがとうございました。
間違いなどあればご指摘いただけると幸いです。
[参考文献]
Goのワークスティーリング型スケジューラ
http://postd.cc/scheduler/
Go言語と並列処理(2)
http://ascii.jp/elem/000/001/480/1480872/
go/src/runtime/proc.go
https://github.com/golang/go/blob/master/src/runtime/proc.go#L25
Scalable Go Scheduler Design Doc
https://golang.org/s/go11sched