引っかかった話
AWS Athena API(AWS SDK for JavaScript)を呼び出してるLambda関数で本当にたまにタイムアウトによるエラーが発生されました。
Lambda関数で設定して置いたタイムアウト時間は40秒で短い時間でしたが、平均2秒±1ぐらいのクエリ時間がたまに40秒を超えるのはおかしいでした。
Athenaの対象データ(S3 Objects)がどんどん増えてAhtenaのクエリが比較的に重くなることはありえますが、速度改善のためパーティショニングも真面目にしているクエリに40秒のタイムアウトに引っかかったのはQuery Running Time (RUNNING)とは違う原因でしょう。
（API呼び出しの前後に時間が秒以上かかるところもありませんでした）
また、AthenaにもAPIごとに 「1 秒あたりのデフォルトの呼び出し数」と 「バーストキャパシティー」のクォータがありますが、これに引っかかったら明確にFAILEDで返してくれるのでこの原因じゃないでした。
もっと確認した結果、たまにQuery Queuing Time(QUEUED)が何十秒も掛かってたことがその原因でした。
QUEUEDステータスとは
QUEUEDステータスはクエリがサービスに提出されたことを示し、クエリがリソースを待ってキューに並んでいた時間(Query Queuing Time)で、Athenaはリソースを利用できる時点ですぐクエリを実行します。
つまり、このステータスは正常な状態で、Query Running Time (RUNNING)とは違います。
Athenaは最近までキューにあるクエリを「RUNNING」として表示してましたが、新しくメトリクスが追加されたそうです。
AWSから回答をもらったそうなstackoverflowの回答を見ると
Take a look on Athena hook in Apache Airflow.
Athena has final states (SUCCEEDED, FAILED and CANCELLED) and intermediate states - RUNNING and QUEUED.
QUEUED is a normal state for a query before it got stared.
...
As part of the deployment of more granular metrics, Athena now includes a QUEUED status for queries.
This status indicates that an Athena query is waiting for resources to be allocated for processing.
Query flow is roughly:
SUBMITTED -> QUEUED -> RUNNING -> COMPLETED/FAILED
試してみる
以下の通りタイムアウトを長くして何回もAPIでクエリを投げて、どのぐらいの頻度で長いQuery Queuing Timeが発生されるか見た結果、意外と頻繁に短いQuery Queuing Timeが発生され、激しい連続クエリを投げた場合は長いQuery Queuing Time時間がたまに発生されますね。
スキャンデータは176KBで2つの2種類のQuery内容をそれぞれ繰り替えながら実行しました。
API呼び出しLambda関数
...
(function loop() {
if (time < 180) {
athena.getQueryExecution(params, (err, data) => {
console.log('Status : ' , data.QueryExecution.Status.State);
if (data.QueryExecution.Status.State == 'SUCCEEDED'){
resolve(queryExecutionId);
} else {
if (data.QueryExecution.Status.State == 'FAILED') {
console.error(err, err.stack);
}
const startMsec = new Date();
while (new Date() - startMsec < 1000);
time+=1;
loop();
}
});
} else {
reject('408 Request Timeout');
return false;
}
}())
...
動作テスト① Lambda関数を連続で3回連続実行する
| 番目 | Query Queuing Time(sec) | トータル処理実行時間(sec) |
|---|---|---|
| 1 | 1 | 4 |
| 2 | 1 | 2 |
| 3 | 16 | 21 |
動作テスト② Lambda関数を連続で4回連続実行する
| 番目 | Query Queuing Time(sec) | トータル処理実行時間(sec) |
|---|---|---|
| 1 | 1 | 3 |
| 2 | 1 | 4 |
| 3 | 1 | 4 |
| 4 | 1 | 3 |
動作テスト③ Lambda関数を連続で6回連続実行する
| 番目 | Query Queuing Time(sec) | トータル処理実行時間(sec) |
|---|---|---|
| 1 | 1 | 3 |
| 2 | 1 | 3 |
| 3 | 1 | 5 |
| 4 | 0 | 1 |
| 5 | 1 | 2 |
| 6 | 1 | 4 |
動作テスト④ Lambda関数を連続で10回連続実行する
| 番目 | Query Queuing Time(sec) | トータル処理実行時間(sec) |
|---|---|---|
| 1 | 1 | 3 |
| 2 | 1 | 2 |
| 3 | 1 | 3 |
| 4 | 1 | 2 |
| 5 | 1 | 3 |
| 6 | 1 | 2 |
| 7 | 0 | 1 |
| 8 | 1 | 3 |
| 9 | 0 | 1 |
| 10 | 1 | 2 |
動作テスト⑤ 長いQuery Queuing Timeが発生されるまで連続実行
| 番目 | アクション | 5秒以上のQuery Queuing Time(sec) |
|---|---|---|
| 1 | 10回連続 | x |
| 2 | 10回連続 | 5秒、7秒が一回ずつ発生 |
| 3 | 10回連続 | x |
| 4 | 10回連続 | x |
| 5 | 20回連続 | 9秒、10秒、14秒、23秒、24秒、38秒、50秒が一回ずつ発生 |
#最後に
自分は今回の対応で単純にタイムアウト時間を長く設定して長くなるケースを許して置きましたが、
クエリの結果を長く待てない利用ケースでしたら、サポートセンターに問い合わせして見た方が良さそうです。
GlueにもAthenaにもクォータがありますが正直にどのクォータに引っかかってQUEUEDになってしまうのか自分の中では不明で、
Query Queuing Timeが長くなるケースを避ける方法を引き続き調べて見るつもりです。
その方法をご存知な方はぜひコメントお願いいたします！