はじめに
この記事は、仕事で使っているgqlgenというGo製のGraphQLサーバーを生成するツールで起きていたgoroutine leakを解消した時のまとめです
起きたこと
GraphQLのSubscriptionを使った機能(リアルタイム性のある機能)をリリースした直後からメモリリークで本番環境のコンテナが死ぬという現象が起きました。
何人かでログを漁ってみたところ、どうやらgoroutineが正常に終了していないままleakしているらしいことが判明(ログなどで本番環境のgoroutine数が異様に増えていたため)
やったこと
まず計測用に埋め込んでいたpprofやPrometheusのエンドポイントを有効にし、ローカル環境下でgoroutineが増大しているかを計測しました
計測には以下のライブラリを使用しました。
すると、Subscriptionを使った機能を使用した際に、goroutineが増加しているのが確認できました。
次に実装の問題なのかライブラリの問題なのかを切り分けることにし、実装側の調査を進めました。
新規で追加されているコード内で数か所goroutineを使っている箇所はありましたが、計測された結果ほど増加している感じではなかったためgqlgen側に問題がありそうと判断。
そこでIssueを漁ってみたところ以下のIssueが見つかりました。
GraphQLのSubscriptionは実装としてWebsocketを使っており、gqlgenではWebsocketのコネクションが接続された際にgoroutineを生成しているようです。
が、Websocketのコネクションが切れた際に生成されたgorutineが正しく終了しないコードになっているため最終的にgorutine leakが発生するということのようです。
修正状況などを確認すると以下のPRで修正されており、v0.17.6で修正が反映されえていることが判明しました
そこで現在使用しているgqlgenのバージョンを確認し、アップデート対応を行いました。
これで大幅にgoroutine数が削減され、leakしなくなりました。
解消したが......
が、その後数日様子を見ていると緩やかではありますがメモリの使用量が増大しており、コンテナが落ちていることが判明。
ローカル環境下でpprofを使い、gorutine数を確認してみたところ僅かにgoroutineが増えていました。
ただ今回はどのAPIを呼び出しても増加しており、その増加量も数件程度。
なので、ライブラリ側というよりはこちらで実装した側の問題の可能性がありそうでした。
pprofとログ埋め込みを併用しつつ、実装を確認したところ別で使用しているRedisクライアントがgoroutineを生成していることがわかりました。
さらに実装を追うと、ミドルウェア層にある実装で都度Redisクライアントが生成されており、その影響でgorutine数が増大しているようでした。
そこでRedisクライアントを一度だけ生成するように実装を変え、最終的な決着をつけました
おわりに
goroutine leakやメモリリークなどはまず計測することから始めるとよいなと再認識。
あとpprofでのgorutine数確認とかが体験が非常に良かった
