はじめに
こんにちは、レバレジーズ株式会社 teratailチームリーダーの竹下です。
弊社では、サーバーをTypeScriptで実装しており、O/R MapperにはTypeORMを使用しています。
今回は、TypeORMの使い方を間違うと、サーバーが不定期にハングアップしてしまうという現象のご紹介です。
もし同じような現象が起きている方がいたら、ご参考になれば幸いです。
起きた現象
サーバーにはAWS Fargateを使っており、gRPCのサーバーとして立ち上がっているのですが、該当のサーバーが不定期に
- CPUが張り付いた状態になるがヘルスチェックは正常なまま
- 一定時間すぎるとOutOfMemoryでタスクが死ぬ
- 自動で新しいタスクが立ち上がるが、1の状態にすぐなってしまう
ということが発生していました。深夜3時や4時などアクセスがほとんど無いようなときに発生していましたし、ヘルスチェックはタスクが死ぬまで正常なままですし、ログにも特にエラーが記録されていなかったので、調査が難航していました。
原因
一番の原因は、DBアクセスのコードでトランザクションを開始した中で更に新しくコネクションを取得しようとしていたことでした。そのコードによりハングアップ状態となり、サーバーで処理が全く行われないという状態になっていました。少し複雑な条件のため、ステップを踏んで説明していきたいと思います。
裏側で起きていたこと
実際の現象の裏では次のようなことが発生していました。
- 原因となるコードが存在するAPI endpointにアクセスが集中(偶然 or クローラーなどがアクセスするページに存在)
- ハングアップが発生し、リクエストをうけつけるが処理が途中で止まっているため、ログ等も出ずにレスポンスを永久に返さない状態に
- リクエストがたまることでメモリ使用量が増えていき、メモリの限界まで来るとOutOfMemoryが発生しタスクが死ぬ
- Fargateがタスクを新しく起動する
ということが繰り返される状態でした。
ハングアップする条件
問題の発生は次の条件が重なったために起きていました
- DBのTransaction内で更に新しいコネクションを取得しようとしているコードが存在する
- ConnectionPoolを利用しており、プールにコネクションが残っていない場合に永久に(または長時間)ブロックする
- 問題のあるコードが同時並列でConnectionPoolのmaxサイズ以上に実行される
なお、上記の条件を満たすだけでこのバグは発生するため、言語、フレームワーク関わらず発生する可能性があります。
問題のコード
for(let i = 0;i < 10; i++) {
startTransaction(async (tr) => {
const conn = await getConnection() // <= ここが問題
})
}
再現するサンプルコードをgithubのこちらのRepositoryに用意しました。実際に動かしてみたい場合は、こちらをご参考に。
何をやっているかと言うと、
ConnecttionPoolののSizeを10としたときに、10並列でDBへのアクセスを発生させているのですが、それぞれのアクセスで
- Transactionの開始
- Transaction内で更に新しいコネクションを取得
だけのコードになっています。
通常だと10並列ぐらいなら何も問題なく終了するはずのコードですが、サンプルコードを実行するとログが途中で止まり一生終了しなくなります。
ハングアップは、Transaction内で新しくコネクションを取得する部分で発生します。
何が起きているか更に詳しく
並列実行数を、コネクションプールのサイズより小さくした場合にはハングアップすることはありません。
つまり、
- Transaction開始時に、ConnectionPoolから1 Connection取得
- それが10並列されると10 Connection取得され、ConnectionPoolの残Connection数が0になる
- Transaction内でさらにConnectionを取得しようとするが、ConnectionPoolにConnectionが残っていないため、そこでブロック
ということが発生してしまっています。この状態になってしまうと、ConnectionPoolからConnectionを取得する部分すべてでブロックされてしまい、ほぼすべての処理が止まるという状態になってしまいます。
解決策
恒久対応
Transaction内で新しくConnectionを取得するコードを撲滅する
これ一択です。
暫定対応
しかし、このようなコードは各所に散らばっており、修正してもレビューやリグレッションテストなども必要なので、適用までに時間がかかります。
なので、暫定対応もいくつか記載しておきます。
- ConnectionPoolでConnectionが取得出来ない場合に、比較的短時間でタイム・アウトするようにする
- ConnectionPoolの上限を非常に大きくしておく
- アイドル時の維持するコネクション数の設定があるConnectionPoolならば、上限は大きくしておいても、そこまでパフォーマンスの影響は受けません
- サーバー台数を増やすし、ハングアップしたサーバーは再起動/停止する
- 並列数が減ればこの現象は起きなくなるので、暫定対処としては十分だったりします
- ConnectionPoolの使用をやめる
おまけ
なぜヘルスチェックは通っていた？
gRPCの前にはNLB(Network load balancer)を置いているのですが、TCPの疎通チェックだけとなるためgRPCのAPIが叩かれていなかったため、ハングアップしていることを検知できていませんでした。
ALBのヘルスチェックはちゃんとgRPCを叩いてくれるのですが、デフォルトでは存在しないAPIを叩き、Unimplementedのエラーが帰ってくることでヘルスチェックをしているので、同様に検知は出来なかったかと思います。