goroutine leakを解消したい！

この記事は、Magic Moment Advent Calendar 2023 15日目の記事です。

こんにちは！
Magic Moment で Backend Engineerをしている 大塚 です。

Magic MomentではGo言語によるマイクロサービス開発をしているのですが、ある日、あるサービスのメモリ使用量が継続的に上昇する現象を観測しました。
そこで、どういった調査をしてどのように解消までいったかをまとめました。

メモリ使用量の上昇を観測

メモリ使用量が日々上昇していることが確認できます。さっそくどこで何が原因でメモリリークしているか確認してみます。

Cloud Profilerで確認

以前よりCloud Profilerを導入していたため、まずはCloud Profilerでメモリ使用量やgoroutineの数を確認しました。
Cloud Profilerについては弊社Tech Lead Miyakeが書いたCloud Profilerを導入してパフォーマンス改善をした話 をチェックしてください。

Cloud Profilerで確認したところ、goroutineの数がどの関数の中で右肩上がりに上昇しているかが分かりました。
画像にはモザイクをしていますが、パッケージ名、関数名などの詳細情報が表示されています。

goroutine leakを解消したい！

いよいよ本題です。

メモリリークの原因はgoroutine leakであること。そして、goroutine leakが発生している箇所がわかったので修正作業に入ります。

該当のコード

※プロダクションコードより変数名、関数名、ロジックを改変しています。

func GetAuth() {
	done := make(chan struct{})

	service1Chan, service1ErrorChan := getService1OAuthResult()
	service2Chan, service2ErrorChan := getService2OAuthResult()

	authChan := fanInAuthFromServices(done, service1Chan, service2Chan)
	errorChan := fanInAuthErrorFromServices(done, service1ErrorChan, service2ErrorChan)

	var authResult *Auth
	var errs []error

	for {
		select {
		case auth, ok := <-authChan:
			if ok && auth != nil {
				authResult = auth
			} else {
				break
			}
		case errChan, ok := <-errorChan:
			if ok && errChan != nil {
				errs = append(errs, errChan)
			} else {
				break
			}
		}
		if authResult != nil || len(errs) > 1 {
			break
		}
	}
	close(done)
}

func fanInAuthFromServices(done chan struct{}, service1Chan, service2Chan chan *Auth) <-chan *Auth {
	result := make(chan *Auth)
	go func() {
		defer close(result)
		for {
			select {
			case <-done:
				return
			case auth := <-service1Chan:
				result <- auth
			case auth := <-service2Chan:
				result <- auth
			default:
				continue
			}
		}
	}()

	return result
}

func fanInAuthErrorFromServices(done chan struct{}, service1Chan, service2Chan chan error) <-chan error {
	// fanInAuthFromServicesのエラー版なので割愛
}

func getService1OAuthResult() (chan *Auth, chan error) {
	resultChan := make(chan *Auth)
	errorChan := make(chan error)
	go func() {
		defer func() {
			close(resultChan)
			close(errorChan)
		}()
		res, err := Service1.GetOAuthResult() // Service1から認証情報を取得する。認証していない場合はerrが返却される
		if err != nil {
			errorChan <- err
			return
		}
		resultChan <- res
	}()
	return resultChan, errorChan
}

func getService2OAuthResult() (chan *Auth, chan error) {
	resultChan := make(chan *Auth)
	errorChan := make(chan error)
	go func() {
		defer func() {
			close(resultChan)
			close(errorChan)
		}()
		res, err := Service2.GetOAuthResult() // Service2から認証情報を取得する。認証していない場合はerrが返却される
		if err != nil {
			errorChan <- err
			return
		}
		resultChan <- res
	}()
	return resultChan, errorChan
}

この処理はgoroutineを活用して、2つの別々のサービスから認証結果を取得する処理です。 結果としては2つのサービスのうちどちらか一方から認証結果を取得できるか、どちらからも取得できないかの2パターンのみを期待しています。

それぞれの処理については以下のようになっています。

• GetAuth関数は全体のフローを制御しています。認証結果が得られた場合や、エラーが2つ以上発生した場合にdoneチャネルを閉じます。
• fanInAuthFromServices関数は、2つのサービスからの認証結果を1つのチャネルに統合するためのgoroutineです。それぞれのサービスから認証情報取得結果をresultチャネルに送信します。doneチャネルが閉じられたとき、このgoroutineは終了します。
• fanInAuthErrorFromServices関数は、2つのサービスからのエラーメッセージを1つのチャネルに統合するためのgoroutineです。それぞれのサービスからエラーメッセージを受け取り、resultチャネルに送信します。 doneチャネルが閉じられたとき、このgoroutineは終了します。
• getService1OAuthResult関数とgetService2OAuthResult関数は、それぞれService1とService2から認証情報を非同期に取得します。認証情報の取得が成功した場合はresultChanに送信し、エラーが発生した場合はerrorChanに送信します。

シーケンス図にまとめるとこんな感じです。

それぞれのチャネルやgoroutineは以下の図でまとめたように相互作用します。

Cloud ProfilerによりGetAuth, fanInAuthFromServices, fanInAuthErrorFromServices の3つの関数でgoroutine leakが発生していることがわかっています。

修正① doneチャネルを受信できているか確認する

閉じられたチャネルからはゼロ値が読み出されるため、常にnilを受信できる状態です。これにより、service1Chan,service2Chanが閉じた後も常にresultに送信を続けるためデッドロックがおきdoneチャネルを受信できないのではないか？仮説をたて修正を試みました。

fanInAuthFromServices関数とfanInAuthErrorFromServices関数を以下のように改修しました。

func fanInAuthFromServices(done chan struct{}, service1Chan, service2Chan chan *Auth) <-chan *Auth {
	result := make(chan *Auth)
	go func() {
		defer close(result)
		for {
			select {
			case <-done:
				return
			case auth, ok := <-service1Chan: // チャネルが閉じられているかチェックするように修正
				if ok {
					result <- auth
				}
			case auth, ok := <-service2Chan: // チャネルが閉じられているかチェックするように修正
				if ok {
					result <- auth
				}
			}
		}
	}()

	return result
}

修正内容としては、読み取った各メッセージに対してチャネルからの読み取りが成功したかどうかを確認するようにしました。

しかし、これはgoroutine leakの解消にはならなかったです。selectはcaseの上から処理するわけではなく選択可能なチャネルをランダムに選定していくため。doneチャネルが閉じられたらdoneのcaseも処理の対象になります。

select, channelの挙動は「初めてのGo言語」がわかりやすかったです。 (全て読めていないのでちゃんと読みます。)

修正② doneチャネルのcloseタイミングを調整してみる

GetAuthでdoneチャネルが正常なタイミングでcloseされてないのではないか？と仮説をたて修正を試みました。

func GetAuth() {
    // 前段の処理は変更なし

OuterLoop:
	for {
	InnerLoop:
		select {
		case auth, ok := <-authChan:
			if ok && auth != nil {
				authResult = auth
			} else {
				break InnerLoop
			}
		case errChan, ok := <-errorChan:
			if ok && errChan != nil {
				errs = append(errs, errChan)
			} else {
				break InnerLoop
			}
		}

		// service1, service2 いずれかの認証情報が取得できた場合、もしくは2つのサービスから認証情報を取得できない場合はOuterLoopを抜ける
		if (authResult != nil && len(errs) >= 1) || len(errs) > 1 {
			break OuterLoop
		}
	}
	close(done)
}

この GetAuth の終了タイミングのブレが goroutine leak の原因でした。

GetAuthが終了する直前にdoneチャネルがクローズされてfanInAuthFromServices, fanInAuthErrorFromServices のgoroutineは終了します。

しかし、独立した getService1OAuthResult または　getService2OAuthResult 内のgoroutineは処理中のままになることがあります。

つまり親のgoroutineが完了したのに、子のgoroutineが完了していない状態になりgoroutine leakとなります。

修正内容としては、GetAuth のループを抜けるタイミングの条件を調整して、getService1OAuthResult と　getService2OAuthResult どちらからも結果が返ってきて処理が終了した状態で GetAuth も終了できるようにしました。

他のgoroutine同様に親の処理が終わった時のdoneチャネルを受け取るか、sync.WaitGroupを使用してgoroutineの完了を待つようにしても良かったかもしれません。

メモリリークの解消を確認

この対応をリリースしたところgoroutine leakが解消されメモリ使用量も落ち着きました！

今後発生させないために

今回の学びから今後 goroutineを扱う設計、開発をする際は以下を意識して行きたいです。

• 親のgoroutineが終了したら、子のgoroutineを終了できるか？
• goroutineの完了順序によって挙動が変わらないか？

今回の対応でselectの挙動など学びがたくさんありました。 当たり前ですが、goroutine, select, channelをちゃんと理解していないと、どこを修正していいか分からない状態になってしまいます。

これらの有名な本で紹介されている並列処理のベストプラクティスやアンチパターンをちゃんと学んでいきたいと思います！

とはいえ便利なツールもあるのでしっかり活用して行きたいです。

goleakを導入する

goleak　は以下の通り、導入が簡単で単体テスト時でgoroutine leakを検出できるため、リリース前に気づけます。

func TestA(t *testing.T) {
	defer goleak.VerifyNone(t)

	// test logic here.
}

プロファイリングツールを導入する

単体テストが整備されてなかったり、プロダクトの利用ユーザーが増えたことで実は昔からあったgoroutine leakが顕在化してしまうなんてこともあるかと思います。

実は今回のgoroutine leakも昔からあったが、あまり使用されない処理だったため気づくことができず。最近、他の改修により頻繁に使用されるようになりgoroutine leakが顕在化しました。

そこで本記事でも活用したCloud Profilerのような、プロファイリングツールを導入しておくとメモリリークにすぐに気付けます。リリース前のQAを行う開発環境でもプロファイルを有効化していくと事前に気づけるかもしれません。

最後に

明日のアドベントカレンダーは照井さんの「データ活用のための履歴データの残し方を考える 」です！

弊社 Magic Moment では、フロントエンド・バックエンドにかかわらず全方位的にエンジニアを募集中です！ Magic Moment に少しでも興味を持っていただけたら是非エントリーください！