ニュース&ブログ
【Redshift】遅いクエリの謎を解け!性能分析入門(原因調査編)
投稿日:2024/03/22
こんにちは!ソリューションサービス事業部の西田です。
最近、Amazon Redshift(※)の利用者から
「具体的に何の処理か分からないけど、な~んか遅く感じるんだよね~」
というような(ふんわりとした)性能劣化に関するお問い合わせをチラホラ受けることがあります。
※AWS が提供するデータウェアハウスサービス。以降、Redshift。
そういったお悩みをお持ちの方が少なからずいるようなので、
今回はボトルネックとなる処理(クエリ)の 特定方法 や 対処方法 について、
具体的な例をもとに解説していきます!
思いの外、記事の内容が超大作になってしまったので、3部構成でお届けします!
本記事の先のお話が気になる方は、以下の記事をご参照ください。
・【Redshift】遅いクエリの謎を解け!性能分析入門(原因究明編)
・【Redshift】遅いクエリの謎を解け!性能分析入門(解決編)
※本記事でご案内する方法はあくまで一例です。
性能劣化の状況によっては、本ブログ記事に記載の対応方法よりも更に最適な
アプローチがあるかもしれないことを念頭に、ご参考ください。
対象者:
・Redshift を利用(他のデータウェアハウスサービスは対象外)
・クエリ(SQL)が管理者ユーザー(例:awsuser)で実行できること
・「自力で性能劣化問題の解決に挑戦したい!」という志しの高い方
原因調査方法:
それでは早速、Redshift 性能劣化における調査方法の 極意 (?)をここでお伝えします。
ここだけの話ですよ!一度しか言いませんからね!!
※ただし、読者は何度も読み返すことは可能ですので、ご安心ください。
私のお勧めは、ずばり「まずは STL_ALERT_EVENT_LOG を見てみよう!」です。
このテーブルには、パフォーマンスの問題を示している可能性のあるクエリ情報(履歴)が記録されています。
そのため、リアルタイムで取得する必要はなく、事象が解消してしまった後でも確認することが可能です。
このテーブルの何が凄いって、
原因(event列)と推奨される 解決策(solution列)を確認することができるんです!!
情報を踏まえて自分で原因を判断する必要も、そこから解決策を考える必要も一切ないんです!
・・・というのは少々大げさですが、このような情報のおかげで、だいぶ対策が検討しやすくなります。
それぞれの原因については、例えば以下のような解説が公式ドキュメントに記載されていて、
結構参考になります。
┌─────────────────────────────────────────────────────────┐
・見つからない統計
統計が見つかりません。データロードまたは大規模な更新の後で ANALYZE を実行し、
COPY 操作で STATUPDATE を使用します。
詳細については、「Amazon Redshift クエリの設計のベストプラクティス」を参照してください。
STL_ALERT_EVENT_LOG – Amazon Redshift
└─────────────────────────────────────────────────────────┘
という訳で、まずは事象が発生している時間帯が STL_ALERT_EVENT_LOG に
含まれているか見てみましょう!
~以降、記載されているクエリは管理者ユーザー(例:awsuser)で実行しています ~
SELECT MAX(event_time), MIN(event_time) FROM STL_ALERT_EVENT_LOG;
max | min |
2024-03-18 04:39:29.784213 | 2024-03-18 01:09:30.9066 |
※このテーブルに格納されているタイムスタンプ列(event_time)は UTC 時刻となっている点にご注意ください。
利用者に確認したところ、問題が発生した時間帯は「日本時刻(JST)の 3/18 AM 10:15~10:17 頃」だったとします。
↑の結果から、UTC 3/18 01:09:30~04:39:29(JST 10:09:30~13:39:29)に事象発生時間帯が含まれていることが
分かったので、今回の場合、本テーブルから調査できる可能性があります。
それでは、詳細を確認してみましょう!
とりあえず、事象発生時間帯以降の情報を取り出してみます。
SELECT * FROM stl_alert_event_log where event_time >= '2024-03-18 01:00:00';
※環境によっては大量レコードが出力される可能性があるため、事象発生時間帯に狭めるなど、条件を絞ってご確認ください。
userid | query | slice | segment | step | pid | xid | event | solution | event_time |
100 | 2018321 | 3 | 0 | 0 | 8277 | 572423 | Very selective query filter:ratio=rows(1)/ rows_pre_user_filter (1048128)=0.000001 |
Review the choice of sort key to enable range restricted scans, or run the VACUUM command to ensure the table is sorted |
2024-03-18 01:17:25.254915 |
今回のケースでは、都合が良いことに 1件だけ結果が表示されました。
query:2018321(今時点で何のクエリかは不明)が実行されていて、2024-03-18 01:17:25(JST 10:17:25)に
「Very selective query filter(Event 列)」というイベントが発生し、本テーブルに記録されたようです。
改めて、AWS の公式ドキュメントを確認してみると、こちらにも今回確認した問題に関する説明が記載されています。
┌─────────────────────────────────────────────────────────┐
・非常に選択的なフィルター
スキャンされた行に対する返された行の比率が 0.05 未満です。スキャンされる行数は rows_pre_user_filter の値であり、返される行数は STL_SCAN システムビューの行の値です。結果セットを決定するために、クエリが著しく大量の行数をスキャンしていることを示します。この問題は、ソートキーが見つからない場合や正しくない場合に起こります。詳細については、「ソートキーの使用」を参照してください。
STL_ALERT_EVENT_LOG – Amazon Redshift
└─────────────────────────────────────────────────────────┘
↑でほぼ説明してくれている気がしますが、もう少し簡潔に要約すると
「読み込まれた行数の5%未満しか結果として返されていないけど、無駄に読み込みすぎじゃない?」
といったことを丁寧に教えてくれているようです。
そして、この問題の対処としては、ソートキー(※)が見つからない or 正しく設定されていない場合に
発生するとのこと。ほぇ~、参考になります。
そんな感じのことが、solution 列(Review the choice of sort key to enable range restricted scans)にも
バッチリ出力されていますね!ご親切にどうもありがとうございます。
※詳細な説明は省きますが、ソートキーとはデータの並び順を決める基準となるカラムのことです。
従来のデータベース(RDBMS)に存在する「インデックス」という仕組みは Redshift では存在せず、
このソートキーという仕組みを使用してデータの並び順を最適化しています。
まとめ:
STL_ALERT_EVENT_LOG を駆使(?)することで、性能劣化に関与している怪しそうな
容疑者(クエリ)は確認できました!
だけど、まだこのクエリが具体的にどんな処理なのかや、何が悪さをしているのかまでは
はっきりと分かっていないので、もう少し調査してみる必要がありそうですね。
次回はこのクエリの正体を暴き、具体的な原因についてこの目で確かめてみましょう!
乞うご期待!
次の記事:【Redshift】遅いクエリの謎を解け!性能分析入門(原因究明編)
西田 幸平(2021年入社)
株式会社システムサポート フューチャーイノベーション事業本部 ソリューションサービス事業部所属
DB(Oracle Database, SQL Server 等)やクラウド(Azure, AWS)を中心とした案件に従事
好きな言葉は『寝る子は育つ』