使用google cloud profiler來對go gRPC server做效能分析
Tags: go, googlecloud, performance, profiling
Published: 2020-11-08 04:15:24

[English version](https://dev.to/billchung/profiling-go-grpc-service-with-google-cloud-profiler-13e4)

# About

這篇文章主要是整合 [Cloud Profiler](https://cloud.google.com/profiler) 至go的程式 (以gRPC Server為範例)

完整的範例在[github](https://github.com/billcchung/example-service/tree/add-ping)

# Profiler
`Profiling`是一種軟體[效能分析](https://zh.wikipedia.org/zh-tw/%E6%80%A7%E8%83%BD%E5%88%86%E6%9E%90)的方法，而`Profiler`則是做`Profiling`的工具。簡單的說它就是測量軟體所花費的時間、空間、或其他的資源，近年來最常用的視覺化工具為`FlameGraph`, 其概念可以參考[Brendan Gregg的網站](http://www.brendangregg.com/flamegraphs.html) 或[google cloud](https://cloud.google.com/profiler/docs/concepts-flame)


### Cloud Profiler

Google出個一個服務叫[Cloud Profiler](https://cloud.google.com/profiler)，它可以讓你非常容易的自動取得並視覺化你的程式，只需要加進一小段簡單的程式碼，以下是一些關於Cloud Profiler的基本資訊：
- 支援的程式語言: `Python`, `Go`, `NodeJS`, and `Java`
- 價格: [`免費`](https://cloud.google.com/stackdriver/pricing#profiler-costs)
- 資料保留時間: [`30天`](https://cloud.google.com/profiler/quotas#retention_periods)
- 對於程式的效能影響: 請參考[這邊](https://cloud.google.com/profiler/docs/about-profiler#performance_impact)
- 就算你的程式不是跑在GCP上，你還是可以使用，以下的範例就是只跑在本機，然後資料會傳送到Cloud Profiler做視覺化

# gRPC server
因為這邊的範例使用gRPC server，所以在介紹整合前先簡單介紹一下該example gRPC service，如果你已經熟悉gRPC service，可以跳過此節

### profobuf - Ping service
該服務只定義了一個`Ping`服務，位於`proto`資料夾，當中[ping.proto](https://github.com/billcchung/example-service/blob/add-ping/proto/ping.proto):

```proto
syntax = "proto3";

package ping;
option go_package = ".;ping";

service Ping {
	// Get returns a response with same message id and body, and with timestamp.
	rpc Get (PingRequest) returns (PingResponse);
	// GetAfter is same as Ping but return the response after certain time
	rpc GetAfter (PingRequestWithSleep) returns (PingResponse);
	// GetRandom generates random strings and return, also produce lots of useless stuff to show the effects of heap
	rpc GetRandom (PingRequest) returns (PingResponse);
}


message PingRequest {
	string message_ID = 1;
	string message_body = 2;
}

message PingRequestWithSleep {
	string message_ID = 1;
	string message_body = 2;
	int32 sleep = 3;
}

message PingResponse {
	string message_ID = 1;
	string message_body = 2;
	uint64 timestamp = 3;
}
```
如果你對於protobuf不熟悉，可以參考[此文件](https://developers.google.com/protocol-buffers/docs/proto3)

這個`Ping`服務有3個RPC (remote procedure call):
  1. `Get`: 單純回傳相同的訊息ID及body, 並帶server的timestamp
  1. `GetAfter`: 與`Get`相同單純回傳，但會等待給定的秒數後再回傳。
  1. `GetRandom`: 與`Get`相似，但body會變成一個隨機的文字，而在下面的實踐上回傳前會故意多做一些事，用意是產生一些cpu及memory用量，作為demo.

### 產生gRPC go code 
1. 需要安裝protoc - 請參考[here](http://google.github.io/proto-lens/installing-protoc.html)
1. 在你的terminal執行以下指令來產生go gRPC server/client codes (會產生一個檔案叫`ping.pb.go`):
  ```bash
make proto-go
  ```
該repository已經包含該`ping.pb.go`檔案，但我使用的版本為
 `protoc-gen-go v1.25.0` & `protoc v3.6.1`，你可能會有不同的版本，所以重新產生以免不相同 

### Ping服務實現
以下是該服務的實踐，該檔案位於`ping`資夾當中的`ping.go`:
```go
package Ping

import (
	"context"
	pb "github.com/billcchung/example-service/protobuf"
	"math/rand"
	"time"
)

var letterRunes = []rune("abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ")

type Server struct{}

func (s Server) Get(ctx context.Context, req *pb.PingRequest) (res *pb.PingResponse, err error) {
	res = &pb.PingResponse{
		Message_ID:  req.Message_ID,
		MessageBody: req.MessageBody,
		Timestamp:   uint64(time.Now().UnixNano() / int64(time.Millisecond)),
	}
	return
}

func (s Server) GetAfter(ctx context.Context, req *pb.PingRequestWithSleep) (res *pb.PingResponse, err error) {
	time.Sleep(time.Duration(req.Sleep) * time.Second)
	return s.Get(ctx, &pb.PingRequest{Message_ID: req.Message_ID, MessageBody: req.MessageBody})
}

func (s Server) GetRandom(ctx context.Context, req *pb.PingRequest) (res *pb.PingResponse, err error) {
	var garbage []string
	for i := 0; i <= 1000000; i++ {
		garbage = append(garbage, string(letterRunes[rand.Intn(len(letterRunes))]))
	}
	return s.Get(ctx, &pb.PingRequest{Message_ID: req.Message_ID, MessageBody: string(letterRunes[rand.Intn(len(letterRunes))])})
}
```

### 設定Cloud Profiler
前面提到只需要加入很簡單的程式碼就可以為你的服務做profiling，你只需要import `"cloud.google.com/go/profiler"`並在你程式啟動的同時啟動profiler即可, 該profiler是一個go routine在背景定時取樣並上傳至cloud profiler

以我們的範列，其程式[如下](https://github.com/billcchung/example-service/blob/add-ping/main.go#L24-L28)(於`main.go`):
```go
profiler.Start(profiler.Config{
	Service:   service,
	ServiceVersion: serviceVersion
	ProjectID: projectID,
})
```
其中
- `Service`為服務名稱,
- `ServiceVersion`服務的版本
- `ProjectID`為GCP的project ID


### 啟動Server服務
在啟動服務之前，請確保你的Cloud Profiler是已經開啟(enabled)的狀態，你可以從[這邊](https://console.cloud.google.com/profiler)開啟

另外因為這個example service並不會跑在GCP裡面，你需要有相對應的cloud profiler權限並確定已經登入glcoud, 若你尚未登入或需要權限請見[這邊](https://cloud.google.com/profiler/docs/profiling-external), 

然後你就可以啟動服務(請將`$PROJECT_ID`換成你的GCP project ID):
```bash
go run main.go -p $PROJECT_ID
```

### 執行client 
一旦server開始執行，你可以執行在`tools`裡面的client端，該程式會依序call `Get`, `GetAfter`, 及 `GetRandom`，你會需要執行多次來確保profiler可以取得樣本:
```bash
for i in $(seq 1 1000); do go run tools/connect.go ; done
```

### 檢視圖表及理解
待client執行一段時間後 (不需要等所有的loop跑完)，你可以在[cloud profiler console](https://console.cloud.google.com/profiler)看到該服務的profiles及其視覺化(flamegraph):

![Screen Shot 2020-11-08 at 10.36.57](https://dev-to-uploads.s3.amazonaws.com/i/uldjjz3336ft0xnsi9v7.jpg)

你所看到的圖可能會跟我的不太一樣，但以我的圖為例
- 它取得16個profiles樣本，其中CPU時間為`520ms`至`780ms`
- `Server.GetRandom`花了不少時間，而該函式為我們為服務所寫的
- 沒有(或極少)`Server.Get`是因為該函式執行時間非常快，也沒有(或極少)`GetAfter` 因為 `time.Sleep`並不佔用CPU時間。你可能會有該兩個函式，但應該極少，因為採樣的角度來說會採到該兩函式的機率太小，而通常我們會使用profiling的時候我們也只在意佔用最多時間或資料的函式。

你可以發現`Server.GetRandom`使用了`164.38ms`，點擊可以看詳細是什麼函式在佔用時間:
![Screen Shot 2020-11-08 at 10.38.01](https://dev-to-uploads.s3.amazonaws.com/i/qjm4oykimnre16cbfgf1.jpg)
你可以看到`growslice`及`Intn`佔了大多數時間:
![Screen Shot 2020-11-08 at 10.38.08](https://dev-to-uploads.s3.amazonaws.com/i/qh5rskj3da1xzq3nttq2.jpg)
![Screen Shot 2020-11-08 at 10.38.14](https://dev-to-uploads.s3.amazonaws.com/i/npxyp6tgho47rp4djhvf.jpg)
當然該兩個函式是go bulitin, 這只是為了demo使用，讓你可以解讀及了解什麼函式佔用了最多的時間，在實務上的程式則可以提供一些資訊來幫忙你做優化

另外在`Profile type`也可以選擇其他的種類，例如選`Heap`來看記憶體使用量:
![Screen Shot 2020-11-08 at 10.38.29](https://dev-to-uploads.s3.amazonaws.com/i/ouund1dugxiqp8infjw8.jpg)
`Server.Random` 使用了 `13.24MiB`

最後值得一提的是`Profile type`中，`Threads`在go裡面指的是[`go routines`](https://github.com/googleapis/google-cloud-go/blob/master/profiler/profiler.go#L31-L34)

其他的資訊可以參考[這邊](https://cloud.google.com/profiler/docs/using-profiler)

# 總結
在這篇文章中簡單的demo了
- 如何使用及解讀Cloud profiler
- 如何建構gRPC server

希望對有所幫助，我選擇gRPC作為範例是為了預計之後一系列的文章以gRPC/microservices為主的後端系統的建置(而非使用REST/json)，以及kubernetes + service mesh的使用, 所有的系統會以GCP或自建為主