サーバーサイドエンジニアの曽根田です。

前回は弊社のサービス開発の裏側を紹介させていただきました。

golangを使って開発したWebAPIを1年半運用して改善してきたことー月間20億PVのマンガサービス開発の裏側

その中で goroutine のパフォーマンスについて、いくつかコメントをいただきました。

そこで本日は InfluxDB Grafana を使用し、golang標準パッケージexpvar からメトリクス情報を取得し、goroutine の数が増加した時の、メトリクスデータをグラフで可視化していきたいと思います。

※データー可視化ツールの Grafana については弊社のインフラエンジニアがPrometheusと組み合わせて監視環境を構築した例を紹介させていただいていいるので、興味のある方はみてください。

1万台のサーバを監視できると話題のPrometheusをGrafanaと組み合わせて導入した話

目的

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