こちらはこの記事の続きです。
今回は、SQL トップ 10 に加えて、SQL トップ 10 の待機イベント内訳も（同じ S3 バケットに別のプレフィックスを付けて）転記します。
待機イベント内訳が必要になるケース
処理時間の長い SQL（文）のチューニングを行う場合、基本的にはEXPLAINなどを使うことで原因調査が可能です。
ただ、
- 単純な
INSERT文や主キーで一意に絞り込んだUPDATE文が遅い - ほかに処理時間が長い更新・削除や DDL が並行して実行された形跡がなく、ロック待ちで遅くなったとは考えづらい
- 特に CPU 使用率や I/O 負荷の上昇なども見られない
など、原因がはっきりしないケースもまれに発生します。
このような場合には、対象の SQL（文）についての待機イベント内訳があると調査しやすくなります。
コードの変更
GitHub にはlambda_function_events.pyというファイル名で置いてありますが、前回と同じファイル名lambda_function.pyの内容を置き換えて登録します（または、Lambda の Handler で呼び出すファイル名を変更します）。
lambda_function.py
import boto3
from datetime import date, datetime, timedelta
import os
import time
db_id = os.environ["DB_ID"]
s3_bucket = os.environ["S3_BUCKET"]
def lambda_handler(event, context):
# 1時間前の時刻を取得（UTC）→対象時間のPerformance InsightsからS3へ
lasthour = (datetime.today() + timedelta(hours = -1)).replace(minute=0, second=0, microsecond=0)
print("Export: " + (lasthour + timedelta(hours = 9)).strftime('%Y/%m/%d %H:00-%H:59'))
# 1分ごとに上位最大10件の正規化SQLを取得してS3へ転記
for minute in range(60):
# Performance Insightsからデータを取得
starttime = lasthour + timedelta(minutes = minute)
metric = "db.load.avg"
periods = 60
groupby = {
"Group": "db.sql_tokenized",
"Dimensions": [
"db.sql_tokenized.statement",
"db.sql_tokenized.id"
],
"Limit": 10
}
filter = {}
response = pi_fetch(db_id, starttime, metric, periods, groupby, filter)
if len(response["Keys"]):
# 対象となる時刻（分単位）のデータがあればS3へ転記（プレフィクスの時刻はJST）
s3_prefix = db_id + "/" + (starttime + timedelta(hours = 9)).strftime('%Y/%m/%d/%Y%m%d%H%M') + "_" + db_id + ".tsv"
exporttime = starttime.strftime('%Y-%m-%dT%H:%M:%SZ')
body_data = "start_time\tsql_tokenized\ttotal\n"
event_s3_prefix = db_id + "_wait_events/" + (starttime + timedelta(hours = 9)).strftime('%Y/%m/%d/%Y%m%d%H%M') + "_" + db_id + "_wait_events.tsv"
event_body_data = "start_time\tsql_tokenized\tevent_type\tevent_name\ttotal\n"
# すべてのKeysから正規化SQLと合計値を抽出
for item in response["Keys"]:
sqltk = item["Dimensions"]["db.sql_tokenized.statement"]
sqlid = item["Dimensions"]["db.sql_tokenized.id"]
total = item["Total"]
body_data += exporttime + "\t" + sqltk + "\t" + str(total) + "\n"
# 正規化SQL別の待機イベントを取得してS3へ転記
event_groupby = {
"Group": "db.wait_event",
"Dimensions": [
"db.wait_event.type",
"db.wait_event.name"
],
"Limit": 10
}
event_filter = {
"db.sql_tokenized.id": sqlid
}
event_response = pi_fetch(db_id, starttime, metric, periods, event_groupby, event_filter)
if len(event_response["Keys"]):
# 対象となる時刻（分単位）の待機イベントがあればS3へ転記
for event_item in event_response["Keys"]:
event_type = event_item["Dimensions"]["db.wait_event.type"]
event_name = event_item["Dimensions"]["db.wait_event.name"]
event_total = event_item["Total"]
event_body_data += exporttime + "\t" + sqltk + "\t" + event_type + "\t" + event_name + "\t" + str(event_total) + "\n"
# S3へ
s3_put(s3_bucket, s3_prefix, body_data)
s3_put(s3_bucket, event_s3_prefix, event_body_data)
return "Completed."
def pi_fetch(db_id, starttime, metric, periods, groupby, filter):
pi_client = boto3.client("pi")
response = pi_client.describe_dimension_keys(
ServiceType="RDS",
Identifier=db_id,
StartTime=starttime,
EndTime=starttime + timedelta(minutes = 1),
Metric=metric,
PeriodInSeconds=periods,
GroupBy=groupby,
Filter=filter
)
time.sleep(0.1)
return response
def s3_put(bucket, key, body):
s3_client = boto3.client("s3")
s3_client.put_object(
Bucket=bucket,
Key=key,
Body=body
)
2021/05/31 追記：
対象インスタンスによっては API のレートリミットに引っかかることがわかりましたので、API 呼び出しごとにtime.sleep(0.1)を入れるようにしました。必要に応じて調整してください。
※複数同時並行で実行すると、高確率で API のレートリミットに引っかかります。ご注意ください。
コード以外の設定は基本的に前回と同じですが、タイムアウト時間のみ 10 ～ 15 分程度に延長します。
実際に使い物になるのか？
…と、ここまで進めておいていまさら感のある話になってしまいますが、分単位の集計情報で実際に使い物になるのか？と言われると正直微妙です。
というのも、
- 原因調査が必要なケースは大体個々の SQL（文）を特定して待機イベントの内訳を把握する必要がある一方、正規化・トークン化した集計を見ても個々の状況は把握しづらい
のと、
- 分単位では多くのケースで粒度が粗すぎて対象の SQL（文）を捕捉できない可能性があり、かといって秒単位では転記に時間が掛かりすぎて実用的ではない
のが主な理由です。
というわけで、使えそうなシチュエーションなら試してみてもいいかもぐらいのスタンスで受け取ってください。