Snowflakeの処理で高コストが発生した際にチェックするポイント

2024年3月23日テクニカルメモ

Snowflakeは利用時間が長ければ長いほどコストがかかる製品です。
そのため、日々どのアプリケーションで、どの処理で、どれくらいコストがかかっているか、利用状況をチェックしたい方が多いのではないでしょうか。

今回は、「WebFOCUS × Snowflake」で発生するコストに関して、以下の3つのテーマを紹介します。

　・WebFOCUSからの利用でSnowflakeにどれくらいのコストが発生しているか確認する方法

　・コストを抑えるために見るべきポイント

　・コストを抑えるための対策

WebFOCUSからの利用でSnowflakeにどれくらいのコストが発生しているか確認する方法

Snowflakeへの接続ユーザやウェアハウス名を確認しよう！

WebFOCUSの処理とそれ以外の処理を分けるため、WebFOCUSからクエリを実行した際に使用されるユーザやウェアハウスを先に確認しておきましょう。

WebFOCUSからの接続時に使用されているユーザやウェアハウスはアダプタの設定から確認することができます。

手順

1)Webコンソールにアクセスして、Snowflakeアダプタのプロパティを開きます。

管理画面にアクセスし、[データの取得]をクリック。

「Snowflake」アダプタをダブルクリックして選択。

アダプタを右クリックし、[プロパティ]を選択。

2)接続先のウェアハウス名を確認します。

[URL]欄のURLから、[warehouse=ウェアハウス名]の記述を確認。

3)ユーザ名を確認します。

[ユーザ]欄から、接続時に使用されるユーザーの名前を確認。

上記例では、「user1」ユーザーで、「WEBFOCUS」ウェアハウスに接続して実行しています。

ウェアハウスアクティビティでウェアハウスごとの利用クレジット数を確認しよう！

Snowflakeの「ウェアハウスアクティビティ」から、ウェアハウスごとに使用されたクレジット数を日単位や時間単位で確認することができます。

ウェアハウスの一覧から、先ほど確認したWebFOCUSで使用しているウェアハウスを選択して、クレジット利用数が許容数より多くなっている日付や時間がないか確認しましょう！

WebFOCUSから接続するウェアハウスを、WebFOCUSの処理専用で利用している場合は、該当のウェアハウスだけに絞り込むことで、WebFOCUSから実行された処理のみのクレジット利用数を確認することができます。

WAREHOUSE_METERING_HISTORY ビューから算出

Snowflakeにデフォルトで作成されている　ACCOUNT_USAGEスキーマ の WAREHOUSE_METERING_HISTORY ビュー を参照することで、SQL文からクレジット利用数を確認することができます。

SQLを使うことで、表形式でクレジット利用履歴を表示することや、クレジット利用量が大きい順に並び変えるなどの加工が可能です。
WAREHOUSE_METERING_HISTORY ビュー | Snowflake Documentation

コストを抑えるために見るべきポイント

許容値を超えるコストがかかっている日付や時間を特定できたら、次に処理時間が長いリクエストを探します。

WebFOCUSからSnowflakeを使用する際に発生する主な課金対象は「ウェアハウスの起動時間」です。
また、クエリが実行されている時間が長いほど、ウェアハウスの起動時間も長くなります。

そのため、処理に時間がかかっているクエリを探すことで、高コストの原因を見つけることができます。

長時間実行されているクエリを確認しよう

クエリ履歴から確認

Snowflakeの[アクティビティ]内にある[クエリ履歴]ページにて、過去のクエリ実行履歴を見ることができます。
[フィルター]からコストのかかっている日付に表示範囲を絞り込んで、各クエリの時間を確認します。

「期間」列でクエリ実行時間を確認することができるので、長時間かかっているクエリを探しましょう。

また、気になるクエリをクリックすると、そのクエリの詳細が表示されます。
どの処理に特に時間がかかっているかなど、より細かくコストが発生している原因を確認することができます。

QUERY_HISTORY ビューから確認

Snowflakeにデフォルトで作成されている　ACCOUNT_USAGEスキーマ の QUERY_HISTORY ビューを参照することで、各クエリの詳細をSQLから確認することができます。

QUERY_HISTORY ビューを使用することで、時間単位での絞り込みや、集計関数を使用したクエリ件数のカウント、キュー時間によるソートなど、クエリ履歴画面では出せない情報も出すことができます。

本ページでは、QUERY_HISTORY ビューで使用できる主な列を紹介します。
ビュー内のすべての列の詳細は、Snowflakeの公式ドキュメントを確認してください！
QUERY_HISTORY ビュー | Snowflake Documentation

■データのソートや絞り込みに使用できる列

列名説明
START_TIME実行開始時間
END_TIME実行終了時間
WAREHOUSE_NAMEウェアハウス名
WebFOCUSからの接続専用のウェアハウスがある場合は、ウェアハウス名で絞り込むことで他のアプリケーションからの実行と分けることができます
USER_NAME実行ユーザ名
WebFOCUSからの接続専用のユーザーを作成している場合は、ユーザ名で絞り込むことでWebFOCUSからの処理だけを抽出することができます

■クエリの分析に使用する列

列名説明
QUEUED_OVERLOAD_TIMEキュー待ち時間（ミリ秒）
仮想ウェアハウスの負荷が高く、実行できなかった時間です
EXECUTION_TIMEクエリの実行時間（ミリ秒）
この列の値が大きい処理があれば、高コストの原因となっているクエリの可能性が高いです
QUERY_TEXT実行されたSQL文の内容を確認できます。

処理時間(EXECUTION_TIME)が長くなっているリクエストを探しましょう!

コストを抑えるための対策

WebFOCUS側で設定できる対策と、Snowflake側で設定できる対策があります。

WebFOCUS側での対策

・最大実行時間(タイムアウト)の設定

・時間のかかるSQLを実行したプロシジャを特定し、プロシジャの内容をチューニング

Snowflake側での対策

・仮想ウェアハウスサイズの検討

・Snowflakeのクエリチューニング
　該当クエリのクエリプロファイルを確認し、
　ボトルネックとなっている処理に応じて、取得データ量(抽出条件)や
　クラスタリングキー、結合キー、実行計画、プルーニングなどを
　見直しましょう

本ページでは、WebFOCUS側でできる対策や、問題のクエリを実行しているWebFOCUS資産の特定方法について具体的に紹介します。

WebFOCUSで最大実行時間の制御(タイムアウト設定)

WebFOCUSには最大実行時間を制御する[connection_limit]という設定がありますが、この設定はWebFOCUSのエージェントを停止することはできても、Snowflake側の処理を止めることができません。

画面上やWebFOCUSログ上でタイムアウトにより処理が止まって見えていても、Snowflake側では処理が継続していることがあります。

WebFOCUS側でSnowflakeのタイムアウト時間を設定するには、「Snowflakeアダプタの接続パラメータにタイムアウトの設定を追加」してください。

設定内容や設定方法の詳細については、以下のページで紹介しています！

Snowflake使用時に長時間実行を防ぐ方法

コストのかかる処理や操作の特定

問題が発生しているクエリの変更を行うには、まずどのプロシジャファイルの実行時にそのクエリが実行されているか特定する必要があります。
実行計画やクラスタリングキーなどはSnowflake側で設定しますが、フィルタ条件の変更やJOIN構文の変更など、SQL文の変更が必要な場合は、SQLを発行しているプロシジャファイルの設定を修正します。

クエリ履歴やQUERY_HISTORY ビューから長時間かかるクエリが特定ができたら、次にそのクエリがWebFOCUSのどのプロシジャから、いつ、誰によって実行されたか確認しましょう。

WebFOCUSでいつどのファイルが実行されたか確認するには、以下のような方法があります。

　・Resource Analyzerを使用する

　・requests.logを確認する

Resource Analyzerを使用する

Resource Analyzerとは、WebFOCUSの利用状況を取得・蓄積・参照することができる機能です。
利用ユーザ、実行レポート、参照テーブル、サーバーリソース状況などの情報を取得し、取得したログ情報を参照することができます。

構成方法などの詳細は以下ページをご参照ください！

実行の裏側丸わかり！利用状況ログの機能教えます | WebFOCUS技術情報サイト

Resource AnalyzerとSnowflakeのクエリ履歴の情報を照らし合わせることで、高コストが発生した資産を特定することができます。

確認手順を紹介します！
※Resource Analyzerが有効になっていることが前提です。

手順

1)Snowflakeにて、長時間実行されているクエリの開始時間を確認します。

2)WebFOCUSのWebコンソール（http://サーバ名:8121/）に管理者ユーザでログインします。

3)画面右上のツールボタンから[リソース管理]をクリックします。

4)[レポート] – [Resource Analyzer] – [パフォーマンス分析] – [長時間リクエスト]を右クリックして実行後、日付範囲を指定して、画面右下の[レポートの表示]をクリックします。

5)プロシジャごとの実行時間平均を見ることができます。特に時間がかかっているプロシジャがどれか見つけましょう！
　また、プロシジャをドリルダウンすると実行開始時間などの詳細を確認することができます。
　Snowflakeログの実行時間と照らし合わせて、Snowflakeの処理に時間がかかっていたリクエストか確認しましょう！

Resource Analyzerで提供されているレポートでは、ソートができない、ドリルダウンしないとリクエストの詳細情報が見れないなど、かゆいところに手が届かない部分もあります。

表示項目やソートの仕方などを工夫して、より見やすいレポートを作成するなら、Resource Analyzerのデータを使ったレポート作成ができる「ログ分析シノニム」もお試しください。

以下のページからファイルや活用方法などの資料をダウンロードできます。
※利用ログの活用資料の注意事項をお読みのうえご利用ください。

ログを活用して定着化を実現！ | WebFOCUS技術情報サイト

requests.logを確認する

requests.logの取得が有効になっている場合は、ログ上で各リクエストの実行時間や、実行URL、実行ユーザを確認することができます。

有効化の方法や、閲覧方法、表示項目の詳細な解説については下記ページで紹介しているので是非ご参照ください！

requests.logの見るべきポイントとは？ | WebFOCUS技術情報サイト

Snowflake側で確認した、時間を要しているリクエストの開始時間/終了時間/処理時間と、ログの記録時間やDB処理時間(SrvDbmsTime)、処理終了時間(Completed)などを照らし合わせることで、該当のリクエストのログを特定することができます。
また、そのログから、実行ユーザ名や実行されたプロシジャの名前を確認することができます。

確認手順の例）

<Snowflakeにてクエリ開始時間、終了時間、実行時間を確認>

　・開始：2023/11/21 17:17

　・終了：2023/11/21 17:22

　・実行時間：5分18秒

　

<該当時間のrequest.logを確認>

[2023-11-21 17:22:48,517] INFO  SrvEnd MonitorID= 52166a57198767d UrlID= URL213 Completed= 17.22.48 ClientUser= snowuser RequestID= URL213Req6 SrvTime= 367262 SrvDbmsTime= 367148 Node= EDASERVE ServerUser= snowuser ReqType= RunFex ReqInfo="Run:Domain=snow/:SubAct=MR_STD_REPORT:Fex=sample" Mime= HTM
[2023-11-21 17:22:48,568] INFO  UrlEnd MonitorID= 52166a57198767d UrlID= URL213 Completed= 17.22.48 UrlStatus= 200 ClientUser= snowuser UrlTime= 367343 ClientCPU= 62 dummy= 0 dummy= 0 SrvReq= 1 SrvTime= 367262 SrvDbmsReq= 1 SrvDbmsTime= 367148 OutputSizeK= 0 ipAddr= 0:0:0:0:0:0:0:1 Method= GET URL= "http://localhost:8080/ibi_apps/run.bip?BIP_REQUEST_TYPE=BIP_RUN&BIP_folder=IBFS:/WFC/Repository/snow/&BIP_item=sample.fex"

※終了時間付近のログを確認します。
※データ転送時間などを含むため、ネットワーク状況やデータ量によってはSnowflake内での処理時間と誤差が発生します。

DBMS時間　　　　：367148ミリ秒
　　　　　　　　　　　SrvDbmsTime= 367148

　実行プロシジャ　：sample.fex
　　　　　　　　　　　Fex=sample

　ファイル保存場所：snowフォルダ
　　　　　　　　　　　Domain=snow/

　実行ユーザー　　：snowuser
　　　　　　　　　　　ClientUser= snowuser

sample.fexというファイルから実行した処理に時間がかかっていることがわかります。

プロシジャファイルのチューニング

問題のあるプロシジャが特定できたら、次はプロシジャの内容をチューニングします。

データ量が多いことが原因で遅延している場合は取得件数を削減するためにフィルタ条件を追加する、結合条件の見直しで改善する可能性がある場合はJOINの条件を変更する、などのプロシジャの変更を行ってください。

プロシジャのチューニング方法に関しては、以下のページで一部紹介していますので、是非あわせてご確認ください。

プロシジャの性能ボトルネックの調査方法 | WebFOCUS技術情報サイト

「遅い…」レスポンス課題の調査・見直し観点は？SQL最適化編 | WebFOCUS技術情報サイト

　

　

WebFOCUSからの利用でSnowflakeがたくさんクレジットを使ってしまった！ というときは、原因となっているクエリがどれかや、なぜそのクエリで多くのクレジットを使ってしまっているのかを特定し、適切な対応を考えましょう。

また、タイムアウト設定など、想定外の長時間実行を避ける対策を事前にしておくと安心です！

テクニカルメモ