Railsのログを awslogs で Cloudwatch Logs に出力する - アクトインディ開発者ブログ

今回はいこレポでのログ出力について紹介します。

いこレポの動作環境

いこレポは ElasticBeanstalk を利用してアプリケーションサーバを稼働させています。 ElasticBeanstalk ではプラットフォームを選択できますが、 Multi Container Docker を利用しています。この場合、実際にRailsが稼働するのは ECS上に起動された Docker コンテナとなります。

Dockerではコンテナ内に永続化するデータを保存しないことが基本ですが、ログもコンテナ削除時に消えていい情報ではないので何らか外に出す必要があります。

その方法としては次の方法があるかと思います。

案1. ホスト側のディレクトリをマウントして、そこにログを保存する
案2. Fluentd でログサーバに転送する
案3. Cloudwatch Logsに転送する

いこレポではECSインスタンスも基本イミュータブルに運用しており、デプロイ毎に新たなインスタンスを起動して、古いのは捨てているのでホスト外に出す仕組みがもう一段必要になります。よって案1は却下しました。

Fluentd を使うと柔軟なログ転送が可能でElasticSearchに送ったりもやりやすいのですが、S3に格納するにしてもログを一旦受けるログサーバを立てる必要があります。ログサーバを立てて運用する手間を惜しんで案2も今回は見送りました。

いこレポで採用したのは案3のClowdwatch logsに出力するという案3の方法。それについて以下に述べます。

Dockerの設定

Dockerにはロギングドライバという仕組みがあり、標準出力に吐いたログを設定されたロギングドライバ経由でハンドリングすることができます。

ロギングドライバには fluentd ¹ や syslog がありますが、Clowdwatch Logsに出すには awslogs を使います。このログドライバは当然、ElasticBeanstalk （具体的にはECS）でも利用できます。

ElasticBeanstalk ではコンテナの定義を Dockerfile や cocker-compose.yml ではなく、Dockerrun.aws.json というAWSの独自フォーマットのファイルに記述します。

次のように設定してやれば、awslogsロギングドライバを利用できます。
logConfiguration がロギングドライバの設定部分です。

{
  "AWSEBDockerrunVersion": 2,
  "containerDefinitions": [
    {
      "name": "rails",
      "image": "<DockerイメージのURL>",
      "essential": true,
      "memory": 1024,
      "entryPoint": ["<略>"],
      "logConfiguration": {
          "logDriver": "awslogs",
          "options": {
            "awslogs-group": "<ロググループ名>",
            "awslogs-region": "ap-northeast-1",
            "awslogs-stream-prefix": "production"
          }
      }
    }
  ]
}

logDriver で awslogsを指定し、options でログの格納先となる Clowdwatch Logsのロググループを指定します。

ログを出力するためには設定以外に次の2点が必要となるので注意です。

出力先のロググループは予め作っておくこと
ElasticBeanstalk でインスタンスの稼働に利用されるロールがそのロググループへのアクセス権を持っていること

Railsの設定

さて、Docker側の設定ができれば、ログの出力先を標準出力にするだけで Clowdwatch Logs にログが保存されるようになります。

Rails5.1では production.rb にもともと次のように定義されており、RAILS_LOG_TO_STDOUT という環境変数があれば、標準出力にログが出力されるようになっています。

  if ENV["RAILS_LOG_TO_STDOUT"].present?
    logger           = ActiveSupport::Logger.new(STDOUT)
    logger.formatter = config.log_formatter
    config.logger    = ActiveSupport::TaggedLogging.new(logger)
  end

ElasticBeanstalk では管理コンソールから環境変数を設定できるのでそれを利用すれば、設定ファイルを変更することなくログを標準出力に切り替えられます。

ログ出力のフォーマット変更

Railsのログは 1リクエストに対して複数行で出力されます。例えば次のように。

Started GET "/" for 172.18.0.4 at 2017-08-16 02:10:36 +0000
Processing by TopController#index as HTML
  Rendering top/index.html.slim within layouts/application
  Rendered top/index.html.slim within layouts/application (***.*ms)
  Rendered layouts/_header.html.slim (**.*ms)
  Rendered layouts/_footer.html.slim (**.*ms)
Completed 200 OK in ***ms (Views: ***.*ms | ActiveRecord: **.*ms)

Clowdwatch logsでは1行が1レコードとなってしまうので、どのレコードからどのレコードまでが一連のログなのか追う必要があり、非常に見づらくなります。 1行のJSONで出力すると1レコードとして一連のログを記録できる上に、パースして見やすくしてくれるので、JSONで出力するようにログフォーマットを定義するようにしました。

いこレポではログフォーマットに roidrage/lograge: An attempt to tame Rails’ default policy to log everything. を利用しています。

まず、production.rb に次の設定を追加します。

  config.lograge.enabled = true
  config.lograge.formatter = Lograge::Formatters::Json.new
  config.lograge.custom_payload do |controller|
    {
      host: controller.request.host,
      remote_ip: controller.request.remote_ip,
    }
  end
  config.lograge.custom_options = lambda do |event|
    exceptions = %w(controller action format id)
    {
      time: event.time,
      host: event.payload[:host],
      remote_ip: event.payload[:remote_ip],
      params: event.payload[:params].except(*exceptions),
      exception_object: event.payload[:exception_object],
      exception: event.payload[:exception],
      backtrace: event.payload[:exception_object].try(:backtrace),
    }
  end

config.lograge.formatter = Lograge::Formatters::Json.new でJSONフォーマッターを使うこと指定して、 config.lograge.custom_payload では標準で出力されている項目以外を追加したい場合に各アプリケーションの要求仕様に沿ってそれを追加するように実装します。

lograge.custom_options ではどの項目をどういうキーでJSONに出力するのかを実装します。ここで定義した、ハッシュがそのまま、JSONとしてログ出力されます。

rescue_from で404や例外をキャッチして、レスポンスをレンダリングしている場合、これだけでは例外情報がログに入りません。そこでapplication_controller.rb で append_info_to_payload をオーバーライドします。こうしておけばバックトレースもログに出力されるようになります。

  def append_info_to_payload(payload)
    super
    if @exception.present?
      payload[:exception_object] ||= @exception
      payload[:exception] ||= [@exception.class, @exception.message]
    end
  end

※ config.lograge.custom_payload を実装せずに、append_info_to_payload のオーバーライドでやってしまってもいいかもしれない。

以上を実施して出力されるログの表示はこんな感じです。 ClowdwatchLog

とても見やすくなります。

最後に

おでかけ先探しに悩むパパ・ママを助けてくれるエンジニアを募集していますので、よろしくお願いします。

脚注

じゃあ、 fluentd のドライバを使えば、ログサーバなしで fluentd で運用できたんじゃない？と思われるかもしれませんが、ロギングドライバがやってくれるのはプロトコルのペイロードに載せて転送してくれるところ。例えばS3に保存するにはどこかで一旦受けて、fluentdの S3アウトプットプラグインでS3に送ってやる必要があるのでログサーバの運用が必要となります。 ↩