ユニファ開発者ブログ

ユニファ株式会社システム開発部メンバーによるブログです。

AWS Lambdaのログを手元へ

久しぶりにブログ書きますUniFaのインフラ見てますすずきです。

あっ、見てますすずきです。って読みづらいですね!!

どうでもいいことは置いておいてさっそく本題へ AWS Lambda ですがサーバレスやマイクロサービスなどで人気ですが。
そのLambdaのログは勝手に保存されていきますよね。(CloudWatch Logsにロググループ作成済みでLambdaに付与したロールに権限があれば…)

CloudWatch Logsのコンソールであれば検索とかできますが、ローカルでgrepとかして検索したいとか言う場合に、 どうやってローカルに持ってくるかの方法を今日は書いてみようと思います。

今回ブログの為にLambdaを準備しますが、 サンプルとして存在している hello-world-python を利用します。

f:id:mominosin:20170728155749p:plain

ファンクション名は hello_world と適当な名前で作成し、 CloudWatch Logsのロググループに /aws/lambda/hello_world を作成しておきます。

f:id:mominosin:20170728160023p:plain

テストを数回実行し、CloudWatch Logsにログが保存されることを確認します。

f:id:mominosin:20170728160412p:plain

これを aws cli を使って取得していきます。

まずは、aws logs describe-log-streams を利用してロググループに存在するログストリームの一覧を取得します。

'->$ aws logs describe-log-streams --log-group-name /aws/lambda/hello_world
{
    "logStreams": [
        {
            "firstEventTimestamp": 1501219199611,
            "lastEventTimestamp": 1501219199612,
            "creationTime": 1501219199581,
            "uploadSequenceToken": "49573804435732851876355987026898819103888646803994710034",
            "logStreamName": "2017/07/28/[$LATEST]4fa773853af4453bb74b768575022823",
            "lastIngestionTime": 1501219214813,
            "arn": "arn:aws:logs:ap-northeast-1:accountid:log-group:/aws/lambda/hello_world:log-stream:2017/07/28/[$LATEST]4fa773853af4453bb74b768575022823",
            "storedBytes": 0
        },
        {
            "firstEventTimestamp": 1501225194981,
            "lastEventTimestamp": 1501225194982,
            "creationTime": 1501225194953,
            "uploadSequenceToken": "49574780945156851939373380344408871750488724095855759202",
            "logStreamName": "2017/07/28/[$LATEST]a49bcda48124475e8ffeb8584f69d478",
            "lastIngestionTime": 1501225210165,
            "arn": "arn:aws:logs:ap-northeast-1:accountid:log-group:/aws/lambda/hello_world:log-stream:2017/07/28/[$LATEST]a49bcda48124475e8ffeb8584f69d478",
            "storedBytes": 0
        }
    ]
}

Lambda のログはリビジョンや時間によってログストリームが別れるので指定したロググループの情報だけあればそいやっと取得できるものではないです。

aws logs get-log-events にロググループとログストリームを指定することで下記の様に情報がとれます。

'->$ aws logs get-log-events --start-from-head --log-group-name /aws/lambda/hello_world --log-stream-name '2017/07/28/[$LATEST]4fa773853af4453bb74b768575022823'
{
    "nextForwardToken": "f/33478306857689294112822718647464261660251560469638152197",
    "events": [
        {
            "ingestionTime": 1501219199616,
            "timestamp": 1501219199611,
            "message": "Loading function\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "START RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159 Version: $LATEST\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "value1 = value1\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "value2 = value2\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "value3 = value3\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "END RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159\n"
        },
        {
            "ingestionTime": 1501219214813,
            "timestamp": 1501219199612,
            "message": "REPORT RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159\tDuration: 0.28 ms\tBilled Duration: 100 ms \tMemory Size: 128 MB\tMax Memory Used: 18 MB\t\n"
        }
    ],
    "nextBackwardToken": "b/33478306857666993367624188005950710991883300639504465920"
}

ちょっと見づらいので jq でログっぽく加工してみます。
timestampの変換方法はこちらを参考にさせていただきました。

jq で エポックミリ秒を変換したい - Qiita

'->$ aws logs get-log-events --start-from-head --log-group-name /aws/lambda/hello_world --log-stream-name '2017/07/28/[$LATEST]4fa773853af4453bb74b768575022823' | jq -r '.events[]|"\(.timestamp|tonumber|./1000|todate) \(.message|rtrimstr("\n"))"'
2017-07-28T05:19:59Z Loading function
2017-07-28T05:19:59Z START RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159 Version: $LATEST
2017-07-28T05:19:59Z value1 = value1
2017-07-28T05:19:59Z value2 = value2
2017-07-28T05:19:59Z value3 = value3
2017-07-28T05:19:59Z END RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159
2017-07-28T05:19:59Z REPORT RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159   Duration: 0.28 ms   Billed Duration: 100 ms     Memory Size: 128 MB Max Memory Used: 18 MB

これらを組み合わせて以下のようなスクリプトをつくって実行します。

for stream in $(aws logs describe-log-streams --log-group-name /aws/lambda/hello_world | jq -rc '.logStreams[].logStreamName'); do
     aws  logs get-log-events --start-from-head --log-group-name /aws/lambda/hello_world --log-stream-name "$stream" | \
         jq -r '.events[]|"\(.timestamp|tonumber|./1000|todate) \(.message|rtrimstr("\n"))"'
done
'->$ bash get_lambda_log.sh 
2017-07-28T05:19:59Z Loading function
2017-07-28T05:19:59Z START RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159 Version: $LATEST
2017-07-28T05:19:59Z value1 = value1
2017-07-28T05:19:59Z value2 = value2
2017-07-28T05:19:59Z value3 = value3
2017-07-28T05:19:59Z END RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159
2017-07-28T05:19:59Z REPORT RequestId: 666e4852-7354-11e7-a78a-272c1f1c9159   Duration: 0.28 ms   Billed Duration: 100 ms     Memory Size: 128 MB Max Memory Used: 18 MB
2017-07-28T06:59:54Z Loading function
2017-07-28T06:59:54Z START RequestId: 5c21af2b-7362-11e7-a234-dd3d9e2db8e5 Version: $LATEST
2017-07-28T06:59:54Z value1 = value1
2017-07-28T06:59:54Z value2 = value2
2017-07-28T06:59:54Z value3 = value3
2017-07-28T06:59:54Z END RequestId: 5c21af2b-7362-11e7-a234-dd3d9e2db8e5
2017-07-28T06:59:54Z REPORT RequestId: 5c21af2b-7362-11e7-a234-dd3d9e2db8e5   Duration: 0.28 ms   Billed Duration: 100 ms     Memory Size: 128 MB Max Memory Used: 18 MB

それっぽいものがつくれたかなと思います。
ローカルにlambdaのログが必要になったらこのようなスクリプト用意してみてはいかがでしょうか?

また、batchなどで随時ログを取得したいなんてこともあるかと思いますがその場合はログストリームの lastEventTimestamp を何処かに保存しておき、次回実行時にログストリーム毎に比較することで更新されたかを判別します。
ログストリームが更新されているようであれば aws logs get-log-events のオプションに --start-time を利用し前回の lastEventTimestamp から +1 した時間からログを取得し始めるなどするとほぼ重複すること無くログを手元に集めることができるかと思います。

いつもにまして簡単な記事でしたが、どなたかの参考になれば幸いです。