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

16364 ワード
APIGateway lambda AWS AWS テキストリンク

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

実行ログは、ステージから設定できます。

設定後、API Gateway にリクエストを投げると、CloudWatch Logs に出力されます。
ロググループ名は、API-Gateway-Execution-Logs_<API ID>/<ステージ名> です。

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

リクエスト/レスポンス

API Gateway に Postman から以下のようにリクエストを投げます。

パスパラメータ groupId=111、クエリパラメータ userId=222、本文に name=hoge を指定しています。

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

Body

Header

実行ログを解説

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

(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 キー に紐づく 使用量プラン をチェックしています。

API キーと使用量プランと API の関係がややこしいですが、20190514 AWS Black Belt Online Seminar Amazon API Gateway の図が視覚的にわかりやすいと思います。

具体的には、メソッドリクエストで API キーの必要性を true することで、API キーを必須にできます。

そして、使用量プランと API を紐づけています。

最後に、API キーと使用量プランを紐づけています。

(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} ですが、ここでは実際にリクエストされたパスが出力されてます。パスパラメータとは、パスに含まれた文字列をパラメータとして扱える機能です。

メソッドリクエストの設定はこちら。

(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}

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

設定はこの部分です。

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

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

この部分で設定したものです。

(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 の統合リクエストはこんな設定です。

(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 署名 が付与されています。

[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 プロキシ統合 なので、そのリクエストフォーマット と一致してます。

(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 プロキシ統合のレスポンスルール に則ってます。

Lambda のコードはこちら。

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

実行に成功しました！ 

(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 のことです。

さいごに

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

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