NEWSニュース&ブログ

【Redshift】遅いクエリの謎を解け!性能分析入門(原因調査編)

この記事は最終更新から1年以上経過しています。内容が古くなっている可能性があります。

投稿日: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:1510:17 だったとします。

↑の結果から、UTC 3/18 01:09:3004:39:29JST 10:09:3013: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件だけ結果が表示されました。

query2018321(今時点で何のクエリかは不明)が実行されていて、2024-03-18 01:17:25JST 10:17:25
Very selective query filterEvent 列)」というイベントが発生し、本テーブルに記録されたようです。


改めて、
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 では存在せず、

   このソートキーという仕組みを使用してデータの並び順を最適化しています。

   参考:ソートキーの使用 – Amazon Redshift

まとめ:

STL_ALERT_EVENT_LOG を駆使(?)することで、性能劣化に関与している怪しそうな
容疑者(クエリ)は確認できました!
 

だけど、まだこのクエリが具体的にどんな処理なのかや、何が悪さをしているのかまでは

はっきりと分かっていないので、もう少し調査してみる必要がありそうですね。
 

次回はこのクエリの正体を暴き、具体的な原因についてこの目で確かめてみましょう!
乞うご期待!


次の記事:Redshift遅いクエリの謎を解け!性能分析入門(原因究明編)

西田 幸平(2021年入社)
株式会社システムサポート フューチャーイノベーション事業本部 ソリューションサービス事業部所属
DB(Oracle Database, SQL Server 等)やクラウド(Azure, AWS)を中心とした案件に従事
好きな言葉は『寝る子は育つ』