API Gateway 開発者に読んでほしい、意味がわかると便利な実行ログ

API Gateway (REST API) では、開発やトラシューに役立つ実行ログ (Execution Logs) を出力することができます。
AWS サポートに問い合わせる際にも、この実行ログがあるとスムーズです。

実行ログは、ステージから設定できます。
![スクリーンショット 2020-10-06 16.07.07.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/1b6b93fc-aef5-04d6-db91-f2dc16371b81.png)

設定後、API Gateway にリクエストを投げると、CloudWatch Logs に出力されます。
ロググループ名は、API-Gateway-Execution-Logs_\<API ID>/\<ステージ名> です。
![スクリーンショット 2020-10-07 17.50.32.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/475c6d59-4eda-ef54-c32c-ee4178b798f7.png)

こちらの実行ログの内容を解説していきます。

## リクエスト/レスポンス
API Gateway に [Postman](https://www.postman.com/) から以下のようにリクエストを投げます。
![スクリーンショット 2020-10-06 16.21.53.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/0f9ab620-518d-61d4-ab53-dfb354226d80.png)
パスパラメータ groupId=111、クエリパラメータ userId=222、本文に name=hoge を指定しています。

API Gateway はこのリクエストを受けると、バックエンドの Lambda が処理して、以下のようなレスポンスを返します。

**Body**
![スクリーンショット 2020-10-06 16.27.08.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/1e85975e-669e-08ea-b9ae-eace1daca1ae.png)
**Header**
![スクリーンショット 2020-10-07 15.24.08.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/fab8115b-4325-6d5c-429b-66b3a1d6f703.png)

## 実行ログを解説
前置きが長くなりましたが、ここからがメインです。
上のリクエストを処理した際の実行ログを読みながら、関連した設定などを解説していきたいと思います。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Extended Request Id: UBuxiEZSIAMFQ1Q=
```
まず、全行の先頭に (a1335dfd-5bcc-4e1b-aa45-f6726cb95816) と出ています。

これは、API Gateway へのリクエストにユニークで付与される ID で、レスポンスの x-amzn-RequestId ヘッダに値が含まれています。この x-amzn-RequestId ヘッダの値から実行ログを検索すると、対象のログを見つけやすいです。

Extended Request Id はレスポンスの x-amz-apigw-id ヘッダの値と合致します。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Verifying Usage Plan for request: a1335dfd-5bcc-4e1b-aa45-f6726cb95816. API Key: **********************************ReKPrb API Stage: **********/test_stage
```

[API キー](https://docs.aws.amazon.com/ja_jp/apigateway/latest/developerguide/api-gateway-api-usage-plans.html) に紐づく [使用量プラン](https://docs.aws.amazon.com/ja_jp/apigateway/latest/developerguide/api-gateway-api-usage-plans.html) をチェックしています。

API キーと使用量プランと API の関係がややこしいですが、[20190514 AWS Black Belt Online Seminar Amazon API Gateway](https://www.slideshare.net/AmazonWebServicesJapan/20190514-aws-black-belt-online-seminar-amazon-api-gateway-230113575/55) の図が視覚的にわかりやすいと思います。

具体的には、メソッドリクエストで API キーの必要性を true することで、API キーを必須にできます。
![スクリーンショット 2020-10-07 15.29.30.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/a889e3c0-7277-348f-e3b5-66de34380c79.png)

そして、使用量プランと API を紐づけています。
![スクリーンショット 2020-10-07 15.37.12.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/2dcaae05-4016-0e5b-039d-7f50a5807511.png)

最後に、API キーと使用量プランを紐づけています。
![スクリーンショット 2020-10-07 15.40.43.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/84e93f1e-f49a-f0a3-d29c-8f41bfc0e21f.png)

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Usage Plan check succeeded for API Key **********************************ReKPrb and API Stage **********/test_stage
```

API キーに紐づく使用量プランのチェックが成功しました。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Starting execution for request: a1335dfd-5bcc-4e1b-aa45-f6726cb95816
```

使用量プランなどのチェックを通過したので、リクエストの処理を開始します。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) HTTP Method: POST, Resource Path: /groups/111
```

HTTP メソッドは POST、パスが /groups/111 です。

リソースでは、パスパラメータ groupId を含んだ /groups/{groupId} ですが、ここでは実際にリクエストされたパスが出力されてます。パスパラメータとは、パスに含まれた文字列をパラメータとして扱える機能です。

メソッドリクエストの設定はこちら。
![スクリーンショット 2020-10-07 15.46.47.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/c784511f-c543-e657-54a7-2ee3fa468a8b.png)


```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) API Key: **********************************ReKPrb
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) API Key ID: 2t1ditjj2d
```

API キーと API キー ID を出力してるだけ。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method request path: {groupId=111}
```

リクエストに含まれるパスパラメータです。

設定はこの部分です。
![スクリーンショット 2020-10-07 17.40.34.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/a3f1af9e-9fe5-b4e8-c39f-416a1f9fe474.png)

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method request query string: {userId=222}
```

リクエストに含まれるクエリパラメータが出てます。

この部分で設定したものです。
![スクリーンショット 2020-10-07 15.54.45.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/893799fc-71b2-6521-3aec-79bf89c57d96.png)

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method request headers: {Accept=*/*, Cache-Control=no-cache, x-api-key=**********************************ReKPrb, User-Agent=PostmanRuntime/7.26.3, X-Forwarded-Proto=https, X-Forwarded-For=72.21.198.64, Host=**********.execute-api.us-east-1.amazonaws.com, Postman-Token=bac61825-0dca-4313-a434-a6d4dbd0ebe2, Accept-Encoding=gzip, deflate, br, X-Forwarded-Port=443, X-Amzn-Trace-Id=Root=1-5f7d5e70-03309b7e6375c2f7116adf86, Content-Type=application/json}
```

クライアントからのリクエストのヘッダです。長すぎる場合は、省略されることがあります。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method request body before transformations: {
    "name": "hoge"
}
```

クライアントからのリクエストの本文です。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Endpoint request URI: https://lambda.us-east-1.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-east-1:************:function:simple-apigw-proxy/invocations
```

バックエンドの Lambda を呼び出すための Lambda のエンドポイントです。

API Gateway の統合リクエストはこんな設定です。
![スクリーンショット 2020-10-07 16.49.59.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/651869/e3278c73-0879-4a5a-9839-b27835ab0f50.png)

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Endpoint request headers: {x-amzn-lambda-integration-tag=a1335dfd-5bcc-4e1b-aa45-f6726cb95816, Authorization=************************************************************************************************************************************************************************************************************************************************************************************************************************05baf7, X-Amz-Date=20201007T062136Z, x-amzn-apigateway-api-id=**********, X-Amz-Source-Arn=arn:aws:execute-api:us-east-1:**********:**********/test_stage/POST/groups/{groupId}, Accept=application/json, User-Agent=AmazonAPIGateway_**********, X-Amz-Security-Token=IQoJb3JpZ2luX2VjENb//////////wEaCXVzLWVhc3QtMSJHMEUCIQDusDo9tWh01W2L0vdTFYePX4ggBm2UCIa5yNJKYzaNrwIgc4+06tbdgd8MV0jllzLICcgM+wEXnul8RUqBqBvDr3YqvQMI////////////ARAAGgwzOTIyMjA1NzY2NTAiDIrJC6+Rp52aVEg1fSqRAy1BbfF8Ry3bub4N1lP8+wRE+pksZ7A0mkIlbC+enCszGV1H5h/ynrutMkLdLbQFHP7hxIwFfpYnXBXWsRHHxfE/k5arLc3ZXbXlBUUtxvACaX67wfOJPuWeA+DfscRnSJg4IY [TRUNCATED]
```

Lambda を呼び出すリクエストのヘッダです。Authorization ヘッダには、Lambda エンドポイントを呼び出すために、[Sig4 署名](https://docs.aws.amazon.com/ja_jp/general/latest/gr/signature-version-4.html) が付与されています。

\[TRUNCATED] とあるように、長すぎるので省略されてますね。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Endpoint request body after transformations: {"resource":"/groups/{groupId}","path":"/groups/111","httpMethod":"POST","headers":{"Accept":"*/*","Accept-Encoding":"gzip, deflate, br","Cache-Control":"no-cache","Content-Type":"application/json","Host":"**********.execute-api.us-east-1.amazonaws.com","Postman-Token":"bac61825-0dca-4313-a434-a6d4dbd0ebe2","User-Agent":"PostmanRuntime/7.26.3","X-Amzn-Trace-Id":"Root=1-5f7d5e70-03309b7e6375c2f7116adf86","x-api-key":"****************************************","X-Forwarded-For":"72.21.198.64","X-Forwarded-Port":"443","X-Forwarded-Proto":"https"},"multiValueHeaders":{"Accept":["*/*"],"Accept-Encoding":["gzip, deflate, br"],"Cache-Control":["no-cache"],"Content-Type":["application/json"],"Host":["**********.execute-api.us-east-1.amazonaws.com"],"Postman-Token":["bac61825-0dca-4313-a434-a6d4dbd0ebe2"],"User-Agent":["PostmanRuntime/7.26.3"],"X-Amzn-Trace-Id":["Root=1-5f7d5e70-03309b7e6375c2f7116adf86"],"x-api-key":["****************************************"],"X-Forwarded- [TRUNCATED]
```

Lambda を呼び出すリクエストの本文です。
[Lambda プロキシ統合](https://docs.aws.amazon.com/ja_jp/apigateway/latest/developerguide/set-up-lambda-proxy-integrations.html) なので、その[リクエストフォーマット](https://docs.aws.amazon.com/ja_jp/apigateway/latest/developerguide/set-up-lambda-proxy-integrations.html#api-gateway-simple-proxy-for-lambda-input-format) と一致してます。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Sending request to https://lambda.us-east-1.amazonaws.com/2015-03-31/functions/arn:aws:lambda:us-east-1:************:function:simple-apigw-proxy/invocations
```

上のヘッダと本文で、Lambda エンドポイントを呼び出しています。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Received response. Status: 200, Integration latency: 341 ms
```

Lambda エンドポイントからレスポンスが返ってきました。ステータスコードは 200 なので成功してます。API Gateway から Lambda エンドポイントにリクエストを投げて、レスポンスが返ってくるまでに 341 ms かかったようです。

Lambda にはコールドスタートと呼ばれる初期化処理がありますが、この時間を含んだものになります。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Endpoint response headers: {Date=Wed, 07 Oct 2020 06:21:36 GMT, Content-Type=application/json, Content-Length=90, Connection=keep-alive, x-amzn-RequestId=133f0a65-dcd1-4fbd-ac83-6be30b413ace, x-amzn-Remapped-Content-Length=0, X-Amz-Executed-Version=$LATEST, X-Amzn-Trace-Id=root=1-5f7d5e70-03309b7e6375c2f7116adf86;sampled=0}
```

Lambda からのレスポンスのヘッダです。

x-amzn-RequestId=133f0a65-dcd1-4fbd-ac83-6be30b413ace は、Lambda のリクエスト ID です。もし、Lambda で原因不明のエラーが起きた場合など、AWS サポートでの調査にはこの値が必要になることがあります。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Endpoint response body before transformations: {"statusCode":200,"body":"{\"groupId\":\"111\",\"userId\":\"222\",\"userName\":\"hoge\"}"}
```

Lambda から返されたレスポンスです。こちらも [Lambda プロキシ統合のレスポンスルール](https://docs.aws.amazon.com/ja_jp/apigateway/latest/developerguide/set-up-lambda-proxy-integrations.html#api-gateway-simple-proxy-for-lambda-output-format) に則ってます。

Lambda のコードはこちら。

```JavaScript
exports.handler = async (event) => {
    console.log(JSON.stringify(event, null, 4));
    const body = JSON.parse(event.body);
    const response = {
        statusCode: 200,
        body: JSON.stringify({
            groupId: event.pathParameters.groupId,
            userId: event.queryStringParameters.userId,
            userName: body.name
        }),
    };
    return response;
};
```

groupId にはパスパラメータの groupId を、userId にはクエリパラメータの userId を、userName にはリクエスト本文の name から取得してます。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method response body after transformations: {"groupId":"111","userId":"222","userName":"hoge"}
```

API Gateway がクライアントに返したレスポンスの本文です。Lambda が返したレスポンス本文の body 部分が使われてますね。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method response headers: {X-Amzn-Trace-Id=Root=1-5f7d5e70-03309b7e6375c2f7116adf86;Sampled=0}
```

API Gateway がクライアントに返したレスポンスのヘッダです。実際には、Content-Type とか Content-Length とかがさらに追加されます。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Successfully completed execution
```

実行に成功しました！ :tada:

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) Method completed with status: 200
```

Lambda からのレスポンスで指定した statusCode に従い、レスポンスのステータスコードは 200 です。

```
(a1335dfd-5bcc-4e1b-aa45-f6726cb95816) AWS Integration Endpoint RequestId : 133f0a65-dcd1-4fbd-ac83-6be30b413ace
```

統合のエンドポイントを呼び出した際のリクエスト ID です。今回は Lambda のリクエスト ID のことです。

# さいごに
実行ログはボリュームが多く読むのが大変ですが、期待しないレスポンスが返ってきた場合など、その原因を調査するためには、実行ログを確認するのが早道です。

ぜひ、実行ログを有効にして、スムーズに開発しましょう。