Kuchitama Tech Note

はてな記法がいつまでたっても覚えられないので、はてなダイアリーからマークダウンが使えるこっちに引っ越してきました。

MakerelでLamdaのColdStartを監視する、をLamdaでやる

この記事はMackerelアドベントカレンダー7日目の記事です。 こんにちは、MackerelアンバサダーのKuchitamaです。 昨日の記事は、 ore-publicさんの運用中に止めたり上げたりするプロセスをMackerelで監視するでした。

本来、「Makerelでエンジニアの退職後も定期バッチをヘルシーに保つTips(仮)」という記事を書く予定でしたが、12/23(月)の MackerelDay#2 のアンバサダーLTで話すことになったので、予定を変更してお送りしております。 元々の内容にご興味あったかたは是非会場にいらしてください。

mackerelio.connpass.com

AWS Lamdaのモニタリング

さて本題。 AWS Lamdaの監視については、 Mackarelでは AWSインテグレーションで実現できます。

mackerel.io

ただ、実運用において重要なメトリクスがありません。 そう、 cold start に関するログです。

cold startの発生率や発生した際の処理時間は、様々な条件で変化します。 そのため、AWS Lambdaを利用する人は様々な方法で、cold startを回避する、もしくは発生時の処理時間を短く抑えています。 この点では非常に多くの施策があるのですが、いざ自分で試すとなると、そういった施策の必要性、緊急性、効果の有無やその大小を計測する必要があります。

そこで、Makerel上でcold startのメトリクスを見れるようにしました。

今回の成果物はGitHubに公開しています。

https://github.com/Kuchitama/mackerel-cloudwatch-logs-metric

cold startの情報はどこにあるか

そもそも、cold startの情報はどこから確認できるのか。 AWS上で確認する方法は2つあります。

  • AWS X-Rray
  • AWS CloudWatch Logs

X-Ray

X-RayAWS上のリクエストをトレースするサービスです。

X-Rayで cold start が発生するリクエストを確認すると、下図のように Initialization という項目が表示されます。 この Initialization が、先の図にある Partial cold start に要した時間を指しています。逆にcold startが起こらない場合、Initializationの項目は表示されません。

https://image.slidesharecdn.com/2018-0205-srv-without-notes-c3782fb1-bc5e-4dd3-9f64-71c276338692-1466883780-180222233128/95/become-a-serverless-black-belt-optimizing-your-serverless-applications-aws-online-tech-talks-57-638.jpg?cb=1519342337

ただし、 X-Ray でこの情報を確認するには、sampling設定を調整して、 cold startが発生したリクエストがサンプリングされている必要があります。 監視という点では、X-Rayは不向きだと言えるでしょう。

CloudWatch Logs

もう一つ、cold startの情報が出力される場所があります。そう、Lambdaの実行ログです。

f:id:kuchitama:20191207135539p:plain
Terminal出力

この実行ログがどこに保存されるかというと、 AWS CloudWatch Logsに保存されています。

f:id:kuchitama:20191207135539p:plain
CloudWatchLogs

そして、 CloudWatch Logsは Insights という機能で、 ログに対してクエリを発行し、パース、フィルター、集計が可能です。

クエリの発行と結果の取得はAPIが提供されているので、プログラムに落とし込むのも容易です。

https://docs.aws.amazon.com/AmazonCloudWatchLogs/latest/APIReference/API_Operations.html

  • StartQuery
  • GetQueryResult

今回は、この機能を使って cold start発生時に Partial cold start にかかる平均時間を取得し、 Mackerelに送信します。

どこでメトリクスを取得するか

severlessアーキテクチャを採用しているのに、監視のためにサーバを用意するのも憚られます。 監視プログラムの実行はLambdaに載せてしまうことにしましょう。 幸い、Lambdaからメトリック送信をされている方はすでにいらっしゃいました。

kmiya-bbm.hatenablog.com

こちらを参考にしつつ、 mkr のバイナリはDockerから取得することにしました。 リポジトリ内の prepare.sh を実行すると、Linux用の mkrバイナリがリポジトリ内に作成されます。

処理の流れ

Lamda function で実行する一連の処理は全て handler.js にまとめています。

Lambda FunctionqueueLambda FunctionqueueCloudWatchLogsCloudWatchLogsDynamoDBDynamoDBLambda FunctiondequeueLambda FunctiondequeueMackerelMackerelstartQueryreturn queryIdput queryIdscanreturn recordsdeletegetQueryResultresultcall "mkr throw"Post metrics

CloudWatchLogs Insight に投げたクエリは非同期に実行されるので、startQuery と getQueryResult の関数を分けています。 queue内で、startQueryで取得した queryId を DynamoDB に保存し、dequeue で読み込み getQueryResultで結果を取得、その結果をMakerelに送信しています。 あらかじめ、Makerelの AWSインテグレーションで、Lamdaの基本的な監視はできているので、今回は同じサービスに対してサービスメトリックとして投稿しています。

Mackrelで見てみると

AWSインテグレーションで取得した 平均処理時間と 今回作成した initialDurationのグラフを並べてみます。 initialDurationの集計が5分おきに実行されるので、スパイクの発生時間に少し誤差がありますが、2つのグラフを並べて同じ画面で見れるので問題発生時の調査が格段にしやすくなりました。

f:id:kuchitama:20191207141230p:plain
カスタムダッシュボード上でグラフを並べて表示

また、Monitorsで閾値を設定することで、サービスの改修を続けるうちにパフォーマンスが悪化してしまうということも検知できるようになりました。

f:id:kuchitama:20191207140032p:plain
アラートの閾値設定画面

まとめ

ということで、 Lamdaを使ってLamdaの監視を実現、特に重要となる cold startのメトリクスをMakerel上で監視できるようになりました。

注意点として、 Lambda, DynamoDB, CloudWatchLogs Insightの料金は従量課金となっています。コストに関してはAWSのドキュメントを確認していただきたいですが、監視の間隔や計測するログデータの量のバランスをとって調整してください。

以上、Makerelアドベントカレンダー7日目の記事でした。 明日は、YujiSoftwareさんが何かツールを作って紹介してくださるようです。

qiita.com

また最後になりましたが、今回の内容について、元となるLamda上でのメトリクス投稿について記事を紹介してくださった a-know さん、そもそも記事を残してくださった kmiya_bbm さん、本当にありがとうございました。 あと、記事書いてる間ほったらかしてる息子よ、ごめんね。

f:id:kuchitama:20191207140547j:plain
ぼっちでYouTubu漬け