クエリログを使ったPostgreSQLの負荷テスト

SREの菅原です。 この記事はカンム Advent Calendar 2022の4日目の記事になります。

少し前にサービスで使っているPostgreSQLをRDSからAuroraに移行しました。 Auroraに移行するため色々と作業を行ったのですが、その中でAuroraの性能を測るために行った負荷テストについて書きます。

pgbench

まず最初にpgbenchを使って、単純なワークロードでのRDSをAuroraの性能差を測ってみました。*1 以下がその結果です。

MySQLで同様のテストをmysqlslapを使って行ったことがあって、そのときは概ねAuroraのほうが性能が高かったので、同様の結果になると考えていたのですが、RDSのほうが性能が高い結果になったのは予想外でした。

ただAuroraのアーキテクチャを考えると、pgbenchのような細かすぎるトランザクションの場合はRDSのほうが性能が高くなることもありそうなことです。

とりあえず、RDSとAuroraの性能比較にpgbanchは参考にはならなさそうなので、別のやり方を考えることにしました。

qrn

過去にMySQLをAuroraに移行したときにはqrnというツールを作って負荷テストを行いました。 PostgreSQLでも log_statement=all を設定することで postgresql.log にクエリログを出力することができます。 同様のやり方でサービスのワークロードを再現できそうなので、クエリログを使って負荷テストをすることにしました。

クエリログの採取

サービスのクエリログを常時出力すると膨大な量になってしまうので、時間を決めて log_statement=all を設定して、一定時間だけクエリログを有効にします。 また、クエリログを採取する前にRDSのスナップショットを作成し負荷テストの事前データとして利用できるようにしておきます。

このときのログの出力先はCloudWatch LogsではなくRDSのファイルにしています。 RDSにはDownloadCompleteDBLogFileという、いつの間にかドキュメントがなくなってしまったAPIがあって、ログファイルをまるごとダウンロードすることができます。*2

クエリログからテストデータへの変換

postgres.logはndjsonではないので、そのままではqrnのテストデータとして利用することができません。 そこでposlogというツールを作って、postgres.logからndjsonに変換できるようにしました。

$ cat postgresql.log
2022-05-30 04:59:41 UTC:10.0.3.147(57382):postgres@postgres:[12768]:LOG:  statement: select now();
2022-05-30 04:59:46 UTC:10.0.3.147(57382):postgres@postgres:[12768]:LOG:  statement: begin;
2022-05-30 04:59:48 UTC:10.0.3.147(57382):postgres@postgres:[12768]:LOG:  statement: insert into hello values (1);
2022-05-30 04:59:50 UTC:10.0.3.147(57382):postgres@postgres:[12768]:LOG:  statement: commit;
...
$ poslog postgresql.log > data.jsonl
$ cat data.jsonl
{"Timestamp":"2022-05-30 04:59:41 UTC","Host":"10.0.3.147","Port":"57382","User":"postgres","Database":"postgres","Pid":"[12768]","MessageType":"LOG","Duration":"","Statement":" select now();"}
{"Timestamp":"2022-05-30 04:59:46 UTC","Host":"10.0.3.147","Port":"57382","User":"postgres","Database":"postgres","Pid":"[12768]","MessageType":"LOG","Duration":"","Statement":" begin;"}
{"Timestamp":"2022-05-30 04:59:48 UTC","Host":"10.0.3.147","Port":"57382","User":"postgres","Database":"postgres","Pid":"[12768]","MessageType":"LOG","Duration":"","Statement":" insert into hello values (1);"}
{"Timestamp":"2022-05-30 04:59:50 UTC","Host":"10.0.3.147","Port":"57382","User":"postgres","Database":"postgres","Pid":"[12768]","MessageType":"LOG","Duration":"","Statement":" commit;"}
...

ndjsonだとjqでパースできるため、クエリの集計や分析がしやすくなるという副次的なメリットもありました。

トランザクションの再現

pgbenchの結果を踏まえるとワークロードのトランザクションも再現する必要があります。 しかし、qrnでワークロードのトランザクションを完全に再現しようと思うと、クエリログをコネクションIDごとのデータに分解して、それらを別々のエージェントで実行する必要があります。

テスト実施の手間がかなり増えてしまい、何回も試行するのた大変になってきます。そこでqrnに新しく-commit-rateというオプションを追加しました。

github.com

そして、どの程度の割合でcommitが実行されているかをクエリログから調べて、それを-commit-rateオプションに設定して、トランザクションを実際のワークロードに似せることにしました。

負荷テストの実施

負荷テストでは、スナップショットをリストアしたRDSとそこから作成したAuroraスレーブ(promote済み)を準備し、クライアントがボトルネックにならいように十分な性能を持ったEC2インスタンスでqrnを走らせました。

詳細はぼかしていますが、サービスのワークロードではAuroraのほうが性能が高いという結果を得ることができました。

まとめ

PostgreSQLの負荷テストの知見がなかったので、当初はどうしようかと考えていたのですが、MySQLでの経験を上手く活かすことができてよかったです。 その後、Auroraへの移行自体は完了して問題なくサービスで稼働しています。

DBの負荷テストまわりの情報はあまり多くないの気がしているので、今後、同様に知見を公開してくれる人が増えるといいなと考えています。