EC2で稼働するAPIサーバのログをCloudWatchに連携してSlackに通知する | Send logs of EC2 based API server to Slack via CloudWatch

ㅤ
　　　　　　₍₍⁽⁽💻₎₎⁾⁾

見て！APIサーバーが動いているよ
かわいいね

　　　　　　　💻

お前らがログを取らないので、エラーでAPIサーバーは死んでしまいました
お前らのせいです
あ〜あ

現状

2台のEC2(Amazon Linux (2ではない))の上で踊るAPIサーバー (Node製)

やりたいことざっくり

これまでログ全然取ってなかった()ので、とりあえずサーバサイドのログを良い感じに残すようにしたい。
かつ、緊急度の高いログはすぐに気づけるようにしておきたい。

考えたこと

• ログはどこかにためておきたい
  • DBにはためたくない
    • 常に使うデータでもないし、無駄にたくさんデータを突っ込みたくない
    • まずはEC2にためるか
  • しかしEC2上にため続けるのは微妙
    • 分析しづらい。いざというときにいちいちSSHログインするの？
    • 無計画に貯めるとEC2の容量限界に達して死亡する (してたのを前々職で見た気がする)
    • そもそもEC2はログをためるための場所ではない
  • CloudWatch Logsにためるのでいかがか
    • EC2よりは分析しやすそうだし、そもそもログ見るためのサービスだし、良さげ
    • ただしログが多くなればなるほどクエリにかかるMoneyが高くなったりする
    • ので、ためておくのは直近のログだけにしておこう
  • 一定期間より前のログはS3にぶちこんでしまう
    • とりあえず置いといて、必要に応じて参照できるようにすれば良い
    • Athenaとかでもクエリできるし、なんならあとでGCPにうつしてBigQuery使うとかでも良い
• エラーを吐いたらすぐに気づきたい
  • 正直メールとかそんなに見ない
    • 仕事中常に見てるのはSlack
    • ログをためる過程でエラーだった場合はWebhookでメッセージ送信できればよさげ
  • アプリケーションコード内にSlack呼び出し書きたくない
    • 業務ロジックに関係無いし、書き忘れたらエラーに気づかないのはイケてない
  • CloudWatch Logsの機能でなにかできないか
    • メトリクスフィルタとアラーム、Lambdaを組み合わせる方法
      • 調べたらすぐ出てくる方法
      • 一見良さげで実装しちゃったが、テストする中で問題点を見つけた
        • アラームの設定むずかしい (理解する脳内リソースが足りなかったw)
        • アラームの挙動が謎 (メトリクス評価期間を1分に設定しても、1分前のデータがなければそれ以前のデータポイントのデータを評価するっぽい)
        • 総じて考えると、今回のように「取りこぼしたくないエラーをもれなく補足する」ためのものではなく、「一度でも起きたらやばいもの」を即座に通知するためのものだと思ったほうが良さそう
    • サブスクリプションフィルタ機能とLambdaを組み合わせる方法
      • ログそのまま流せるし、こっちのほうが用途にあってそう
      • ほぼリアルタイムでエラーログ検知できる
      • ただしログが出る度にほぼ毎回Lambdaを呼び出すことになる
        • 正直Lambdaはそんなに詳しくないのでなんとも言えないが、料金とか同時実行数とか気にしたほうが良さそう
        • ここまで考えるならアプリケーションコード内でSlack呼び出したほうが良いのでは感も正直あるが、とりあえず実装してみる

作業を分解する

1. ログをEC2にためる
2. EC2からCloudWatch Logsに連携する
3. CloudWatch Logs上でのログの寿命を決める
4. CloudWatch LogsからサブスクリプションフィルタでLambda -> ログを解析してエラー系ならSlackに流す
5. CloudWatch LogsからS3にログ連携する (今回ここまではやらないが方針だけ決める)

ログをEC2にためる

今回Nodeを使っているので、log4js-nodeを使う。
ログのレベリングや出力先やログローテーションをかんたんに設定できる。

cf) ログローテーションとは
参照元: IT用語辞典
ログローテーションとは、システムが残す記録（ログ）が際限なく増えることを防ぐために、一定の容量や期間ごとに古いログを削除したり新しいログで上書きすること。また、そのような機能。

他にもいくつかライブラリはあるが、既にこいつが入っていたのと昔も使ってたのでそのまま使う。

ちなみにpm2で動かしている場合、log4jsのconfigurationにpm2: trueを入れてあげないとうまく動かない。

こんな感じでLoggerを設定してあげて

logger.ts

import { configure, getLogger } from "log4js"
import * as path from 'path'

const log4jsConfig = {
  pm2: process.env.NODE_ENV !== "development" ? true : false,
  appenders: {
    application: {
      category: "application",
      type: "dateFile", // 日にちでログローテーションする
      daysToKeep: 7 // ログを保存する日数
      filename: `${path.join(__dirname, "../log")}/application.log`, // ここで出力先を決める
      alwaysIncludePattern: true // .yyyy-MM-dd などのパターン文字列を常にファイル名に含める
    },
  },
  categories: {
    default: {
      appenders: ["application"],
      level: "ALL"
    },
    application: {
      appenders: ["application"],
      level: "ALL" // 既定値のレベル(FATAL, ERROR, WARN, INFO, DEBUG, TRACE)を全て出力する
    },
  }
}

configure(log4jsConfig)

export const applicationLogger = getLogger("application")

使う側では

sample.ts

import { applicationLogger } from "./Logger"

applicationLogger.info('This is test log.')
applicationLogger.error('This is test log.')
applicationLogger.fatal('This is test log.')

という感じで使える。
上記設定の場合、アウトプットは下記のようになる。

log/application.log.2020-03-12

[2020-03-12T02:57:22.528] [INFO] application - This is test log.
[2020-03-12T02:57:22.528] [ERROR] application - This is test log.
[2020-03-12T02:57:22.528] [FATAL] application - This is test log.

EC2からCloudWatch Logsに連携する

ログを貯められるようになったら次はCloudWatch Logsに連携する。

CloudWatch Logsエージェントというのが用意されているので、それを使う。

一応公式資料はこちら

だけどやっぱり分かりづらいのでざっくり解説します。

CloudWatch Logs エージェントとは

ログファイルを監視して、更新があった場合には差分をCloudWatchに送信してくれるやつ。

なお、CloudWatchエージェントというやつもいて、こっちの方が新しく、かつLogsの方は廃止予定らしいので、気になる方はLogsついてないほうをインストールしたほうが良いです。

今回必要な機能の部分については大きく変わるものではないはず。

参考

EC2に、CloudWatch Logsの操作権限を追加する

わかりにくいと悪名高いIAMを設定する必要があります。

ちゃんと書くと結構な分量になるので割愛しますが、EC2に下記の権限が割り当てられていればOKです。
ちなみにterraformです。

resource "aws_iam_policy" "api_cw_logs" {
  name        = "EC2-CloudWatchLogs"
  path        = "/"
  description = "Allow sending log to CloudWatch"
  policy      = <<EOF
{
  "Version": "2012-10-17",
  "Statement": [
    {
      "Effect": "Allow",
      "Action": [
        "logs:CreateLogGroup",
        "logs:CreateLogStream",
        "logs:PutLogEvents",
        "logs:DescribeLogStreams"
      ],
      "Resource": [
        "arn:aws:logs:*:*:*"
      ]
    }
  ]
}
EOF
}

CloudWatch Logs エージェントのインストール

Amazon Linux前提で書いていきます。

まずはAPIサーバの載ってるEC2にSSHログインしましょう。
その上で、下記コマンドでエージェントをインストールします。

sudo yum update -y
sudo yum install -y awslogs

エージェントの設定

1. リージョンの設定
2. 出力ログの設定

を行います。

リージョンの設定

これは地味に罠で、CloudWatch Logsエージェントのデフォルトリージョンはus-east-1になっている。
普段見ているリージョンがap-northeast-1の人は、「ちゃんと設定してるはずなのにログが出ない」問題に悩まされるケースあり。

設定ファイルは/etc/awslogs/awscli.confなので、vimなりで開きましょう。

なおec2-userでログインしている場合sudoで開かないと編集権限が無いため気をつけてください。

また、awslogsのインストールの仕方によっては設定ファイルの場所が違うっぽいので、もし上記にデフォルトのファイルが無かったら疑ってください。

sudo vim /etc/awslogs/awscli.conf

/etc/awslogs/awscli.conf

[plugins]
cwlogs = cwlogs
[default]
- region = us-east-1 # こいつを
+ region = ap-northeast-1 # こっちに変える

出力ログの設定

設定ファイルは/etc/awslogs/awslogs.confです。

また、awslogsのインストールの仕方によっては設定ファイルの場所が違う(ry

sudo vim /etc/awslogs/awslogs.conf

で、一番下に下記を追記します。

/etc/awslogs/awslogs.conf

[/home/ec2-user/log/application.log]
file = /home/ec2-user/log/application.log.* # log4jsで設定した出力先を入れる
log_group_name = api # CloudWatch Logsのロググループ名。もっとわかりやすい名前を設定するのが吉
log_stream_name = {instance_id}/home/ec2-user/log/application.log # ロググループ内のログストリーム名
datetime_format = %Y-%m-%dT%H:%M:%SZ # タイムスタンプのフォーマット

エージェントを起動する

起動コマンド

sudo service awslogs start

ちゃんとスタートしているかを確認するなら

cat /var/log/awslogs.log

で、こんな感じのログが出るようになってれば問題ないはず

2020-03-12 06:22:25,268 - cwlogs.push.stream - INFO - 17305 - Thread-1 - Starting publisher for [811461142fa2f7e3020774f08be5083d, /var/log/messages]

これで設定完了なので、CloudWatchを確認しに行きましょう〜
リージョンを間違えないように！

CloudWatch Logs上でのログの寿命を決める

これはかんたんで、AWSのGUIでぱぱっと設定しちゃいましょう。

CloudWatchのロググループ一覧は上記のようになってると思います。
対象ログの「次の期間経過後にイベントを失効」部分をクリックすると、ログの保存期間の設定ダイアログが出るのでそこでお好みの期間に設定しましょう。

CloudWatch LogsからサブスクリプションフィルタでLambda -> ログを解析してエラー系ならSlackに流す

めちゃ地味な機能で「AWS、あんまりこの機能使ってほしくないのでは」邪推してしまいそうなんですが、、
サブスクリプションフィルタという、ログ内容を所定の条件でフィルターした上で、指定した連携先に流す機能が実はあります。

前項のロググループの画像の状態で、特定のロググループを選択し、上の方にある「アクション」プルダウンを表示させるとその一番下に「サブスクリプション」があります。
わかりづらすぎて草。

AESにも流せるので試してみたい感あるけど、今回はLambdaに流しましょう。

Lambda functionの実装

さて、いずれにしても流し先のLambdaが存在しないと作れないので、Lambda関数を実装しましょう。
普段TS使ってますが、環境つくるのめんどくさそうだったのでとりあえずJSで書いてしまってます。反省。

zlibパッケージは、ぐぐったらみんなそれ使ってたので使ってます。
axiosは、Slack送信した昔のコードそのまま使ったので入れてるだけです。
適宜ご自分の好みに改変してください。

notify-api-error-to-slack.js

const zlib = require('zlib')
const axios = require("axios")
const awsSDK = require('aws-sdk')

const cwLogs = new awsSDK.CloudWatchLogs()

const unzip = (buffer) => new Promise(resolve => {
  const base64Logs = new Buffer(buffer, 'base64')

  zlib.gunzip(base64Logs, function (err, bin) {
      if (err != null) throw err;
      resolve(bin.toString('ascii'))
  })
})

exports.handler = async function(event, context) {
  try {
    const unzippedLog = await unzip(event['awslogs']['data'])
    const parsedLog = JSON.parse(unzippedLog)
    const { logEvents } = parsedLog

    if (!logEvents.length) {
      return context.succeed()
    }

    const warnEvents = []
    const errorEvents = []
    const fatalEvents = []

    logEvents.forEach(event => {
      switch (true) {
        case (event.message.includes('WARN')):
          warnEvents.push(event)
          break
        case (event.message.includes('ERROR')):
          errorEvents.push(event)
          break
        case (event.message.includes('FATAL')):
          fatalEvents.push(event)
          break
        default:
          break
      }
    })

    const messagePromises = []

    if (warnEvents.length) {
      messagePromises.push(
        sendSlackMessage(
          'notify_api_warn',
          ['<!channel>\n'].concat(warnEvents.map(event => event.message)).join('\n')
        ).catch((err) => { console.log(err) })
      )
    }

    if (errorEvents.length) {
      messagePromises.push(
        sendSlackMessage(
          'notify_api_error',
          ['<!channel>\n'].concat(errorEvents.map(event => event.message)).join('\n')
        ).catch((err) => { console.log(err) })
      )
    }

    if (fatalEvents.length) {
      messagePromises.push(
        sendSlackMessage(
          'notify_api_fatal',
          ['<!channel>\n'].concat(fatalEvents.map(event => event.message)).join('\n')
        ).catch((err) => { console.log(err) })
      )
    }

    // 各送信のエラーは握りつぶす
    await Promise.all(messagePromises).catch((err) => { throw err })

    return context.succeed()
  } catch (err) {
    return context.fail(err)
  }
}

async function sendSlackMessage(channel, message) {
  return axios({
    headers: {
      "Content-type": "application/json",
      Accept: "application/json",
      Authorization: `Bearer API_KEY` // 自分のAPI_KEYいれましょう
    },
    method: "POST",
    url: "https://slack.com/api/chat.postMessage",
    data: {
      channel: `${channel}${genEnvSuffix()}`,
      text: message,
      username: "sample-bot"
    }
  })
}

function genEnvSuffix() {
  switch (process.env.NODE_ENV) {
    case "production":
      return ""
    case "staging":
      return "_stg"
    case "development":
    default:
      return "_dev"
  }
}

LambdaをCloudWatch Logsから呼び出せるようにする

別サービス -> Lambdaを呼び出す形式の場合、「別サービス側でLambdaへのアクセス権限を付与する」というよりは、「特定のLambda function側で、誰が自分を呼び出せるのかを定義する」形になります。

な、何を言っているのかわからねーと思うが、俺もよくわからねえ。

terraformだと下記のような設定をすることになります。

resource "aws_lambda_permission" "with_api_error_cloudwatch" {
  statement_id  = "AllowExecutionFromCloudWatch"
  action        = "lambda:InvokeFunction"
  function_name = "${aws_lambda_function.notify_api_error_to_slack.function_name}"
  principal     = "logs.ap-northeast-1.amazonaws.com"
  source_arn    = "${aws_cloudwatch_log_group.api_application.arn}"
}

api_applicationというロググループから、notify_api_error_to_slack関数を呼び出せる設定をしてます。

Lambdaの定義は省略します。

サブスクリプションフィルタを用意する

GUIなら、上の方で紹介した「アクション」の中から「AWS Lambdaへのストリーム」を選択していけば良いです。

ちなみにterraformだと下記な感じで設定できます。

resource "aws_cloudwatch_log_subscription_filter" "api_application_error_to_lambda" {
  name            = "api_error_slack_notification_lambda_logfilter"
  log_group_name  = "${aws_cloudwatch_log_group.api_application.name}"
  filter_pattern  = "?FATAL ?ERROR ?WARN"
  destination_arn = "${aws_lambda_function.notify_api_error_to_slack.arn}"
}

今回は、log4jsで定義されているエラー系のやつを全て補足したいので、?FATAL ?ERROR ?WARNをフィルターパターンに設定しています。

これは、「FATALもしくはERRORもしくはWARNのいずれかがログイベント文字列に含まれていれば」という意味になります。

詳細はこちらで。

動くか試してみる

ここまでできたら動くはず。テストしましょう。

いちいちエラー発生させるのはめんどいので、ログファイルに適当な文字列を突っ込んで検証します。
再度APIサーバにSSHログインして、ログディレクトリに移動して下記コマンド。

echo "ERROR: this is test log" >> application.log.2020-03-13

やったぜ。

CloudWatch LogsからS3にログ連携する

さて、ここまででログためて、必要に応じてSlack通知する仕組みはできました。

あとはS3にデータ保存するだけ。

リアルタイムで保存していくならKinesis firehoseを使う手もあるが、よく事例で出てくるのはサブスクリプションフィルタを使ったもの。

実はサブスクリプションフィルタは1ロググループに対して1つしか用意できないため、既にこの手は封じられている😭

ただ、ぶっちゃけリアルタイムで保存する必要はないので、バッチ処理で1日1回、S3に保存するタスクが走れば良いと考えよう。

そもそもCloudWatch LogsにはS3へのエクスポート機能がある。
GUIでも操作できるが、人間バッチはイケてないので、バッチ機構を作って下記APIを叩くようにするのが良いでしょう。

以上

さすがに全てを詳細に記述するのはToo muchなので割愛しまくりましたが、大まかな方針として、ロギング周りをこれから実装する方の参考となれば幸いです。

もしもっと詳細が知りたい部分などありましたら、コメントなり編集リクエストなりいただければと思います。