こんにちは、開発本部の植江田和成です。
私は2021年8月ごろより WebClipping の開発リーダーとして業務を行なっています。
WebClipping とは様々なサイトから記事をクロールし、その記事にユーザーが設定したキーワードが含まれていればクリップしたりなど、メディア露出の調査・分析などがおこえるWebアプリケーションです。https://webclipping.jp/
今回は、そのWebClippingでAmazon RDS for MySQL(以降MySQL)のアップグレードを実施した後に発生したスロークエリとその改善を行なったことを書きます。
RDS for MySQLは5.6のサポートが終了するため、2022年3月1日までにバージョン5.7までアップグレードすることが強く推奨されています。WebClippingではMySQLバージョン 5.6を使用していたため、この対応が必須でした。
参考リンク: https://aws.amazon.com/jp/blogs/news/amazon-rds-for-mysql-5-6-extending/
今回書くのは、MySQL のアップグレード後に起きたケースですが、アップグレード後ではなくともスロークエリは発生します。
スキーマやクエリによって対応方法は変わるかと思いますが、こういう解決方法もあるということで読んでいただければ幸いです。
*この記事に書かれてあるクエリやスキーマは一部簡略化されています。
なぜスロークエリが生まれるのか?
そもそもなぜスロークエリが生まれるのでしょうか? 単純に適切なインデックスがない場合も考えられますが、主に3点あると思います。
- インデックスの統計情報が狂ってしまった。
- OPTIMIZER の実装が変わって、これまでと異なるインデックスが
選択されるようになった。 - 適切にインデックスが貼られていないテーブルで、バージョンアップ後に予想以上に
パフォーマンスが落ちてしまった。
まず1についてですが、インデックスの統計情報は OPTIMIZER が実行計画を選択するのに必要な情報です。この統計情報が狂ってしまったために、OPTIMIZER が良い選択をできない様なパターンです。
次に2ですが、これはアップグレードした際に OPTIMIZER の実装が変わってしまったために起きるパターンです。
最後に3です。これが今回のスロークエリが発生した原因です。
スキーマは後述しますが、予想以上にパフォーマンスが落ちてしまいました。
Clipping で発生した実例
MySQL アップグレードメンテナンスを実施した次の日に、クロールに必要な処理が圧倒的に遅いことがわかりました。発覚時点では通常に動作する場合と比べて約1/5ほどでしか処理が進んでいませんでした。
原因が前日に実施されたMySQLアップグレードによる影響であることを疑い、スロークエリが出ていないかすぐに調査を開始しました。
しかし、調査をするに当たって重要な問題があることに気づきました。
それはスロークエリを出力する設定になっていなかったことです。
本番環境のMySQLのスロークエリログを確認しようとしたのですが、どこにもログが出ておらず、MySQLの設定を確認したところなんとスロークエリログが出力されない設定になっていました。
早急にスロークエリログを出力するように設定を行います。
ClippingではRDSを使っていたためパラメータグループを変更して、スロークエリの設定をできる様にする必要がありました。
なので緊急メンテナンスを実施し、パラメータグループを変更した後で以下のクエリを実行しました。
パラメータグループについて: https://docs.aws.amazon.com/ja_jp/AmazonRDS/latest/UserGuide/USER_WorkingWithParamGroups.html
SET GLOBAL slow_query_log = 'ON';
これで設定は完了です。
しばらく待って、スロークエリを確認してみるとクロール処理に重要な以下のクエリが出力されました。
SELECT count(con_id) as cnt FROM table_name
WHERE sns_check_flag = 1
AND c_id = :c_id
AND created_at >= :created_at
AND created_at <= :created_at;
どう改善するのか?
スロークエリが特定できたので、改善します。
まずは EXPLAIN を実行して、実行計画に関する情報を確認します。
参考: https://dev.mysql.com/doc/refman/5.7/en/explain.html
EXPLAIN SELECT count(con_id) as cnt FROM table_name
WHERE sns_check_flag = 1
AND c_id = :c_id
AND created_at >= :created_at
AND created_at <= :created_at;
id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
1 | SIMPLE | table_name | NULL | index_merge | c_id,created_at,sns_check_flag | c_id,sns_check_flag | 4,4 | NULL | 34810 | 10.21 | Using intersect(c_id,sns_check_flag); Using |
EXPLAIN 結果から type が index_merge になっていることがわかります。index_merge は複数のインデックスから取得したデータを並び替えたりフィルターをしているため重いクエリになりがちです。
また possible_keys を見てみると、optimizer は sns_check_flag も使うことを候補としてあげており、key にも書かれているので使われていることがわかります。
結果 sns_check_flag = 1 に該当するデータが少なく、一部のクエリに対して、sns_check_flag 単体のインデックスも利用した方が高速であると optimizer が判断していることが判明しました。
参考: https://dev.mysql.com/doc/refman/5.7/en/explain-output.html
該当テーブルのスキーマ
CREATE TABLE `table_name` (
`id` int(13) NOT NULL AUTO_INCREMENT,
`c_id` int(13) NOT NULL,
`con_id` int(13) NOT NULL,
`s_id` int(13) NOT NULL DEFAULT '0',
`pub_flag` int(3) NOT NULL DEFAULT '0' ,
`sns_check_flag` int(1) NOT NULL DEFAULT '0',
`sns_check_id` int(13) NOT NULL DEFAULT '0',
`sns_facebook_count` int(13) NOT NULL DEFAULT '0',
`sns_tweet_count` int(13) NOT NULL DEFAULT '0',
`sns_total_count` int(13) NOT NULL DEFAULT '0',
`image_check_flag` int(1) NOT NULL DEFAULT '0',
`image_error_num` int(1) NOT NULL DEFAULT '0',
`created_at` datetime NOT NULL,
`updated_at` datetime NOT NULL,
PRIMARY KEY (`id`),
KEY `c_id` (`c_id`),
KEY `con_id` (`con_id`),
KEY `created_at` (`created_at`),
KEY `pub_flag` (`pub_flag`),
KEY `s_id` (`s_id`),
KEY `sns_check_flag` (`sns_check_flag`),
KEY `sns_check_id` (`sns_check_id`),
KEY `sns_facebook_count` (`sns_facebook_count`),
KEY `sns_tweet_count` (`sns_tweet_count`),
KEY `sns_total_count` (`sns_total_count`),
KEY `image_check_flag` (`image_check_flag`),
KEY `image_error_num` (`image_error_num`)
) ENGINE=InnoDB AUTO_INCREMENT=271827426 DEFAULT CHARSET=utf8;
スキーマからも見てわかる様に適切なインデックスが貼られていません。ほぼ全てのカラムに乱雑に貼られている状態です。
そこで ALTER TABLE を実行して適切なインデックスを貼り直します。
ALTER TABLE table_name
ADD INDEX c_id_sns_check_flag_created_at(`c_id`,`sns_check_flag`, `created_at`), LOCK=NONE;
今回の解決策としては、sns_check_flag カラムもインデックスに含んだ複合インデックスを作成することでスロークエリになっていたクエリのパフォーマンスが改善しました。
id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
1 | SIMPLE | table_name | NULL | range | c_id,created_at,sns_check_flag,clip_id_created_at,c_id_sns_check_flag_created_at | c_id_sns_check_flag_created_at | 13 | NULL | 845 | 100.00 | Using index condition |
type が index_merge から range に代わり、key をみると ALTER TABLE で実行した c_id_sns_check_flag_created_a の複合インデックスがちゃんと使われていることが確認できました。
最後に
今回の対応で、スロークエリが出た場合の対応方法と、スロークエリを確認することがいかに重要かがわかりました。
このほかにも Clipping には、Elasticserach, MongoDB などでレガシーな箇所が多く存在しています。パフォーマンス改善に興味がある方は、ぜひ応募フォームよりご応募よろしくお願いいたします!
https://prtimes.co.jp/recruit/