sekaie engineers' blog

セカイエ株式会社が主催するエンジニア勉強会について

セカイエのアラート監視周りについての雑多書き

おはようございます。こんにちは。こんばんは。

佐々木です。

キリスト教ではありませんが、アドベントカレンダーの1日目を担当します。どうぞよろしくお願いします。

サンタさんに何買ってもらおうかなあ。。。

qiita.com

今日はセカイエのアラート周りについて書きます。

まあまずはじめに

セカイエでは AWS を使ってサービスを展開しています。主にEC2です(ほぼEC2です)

AWSには CloudWatch というサービスがありますね。

aws.amazon.com

RDSやEC2のメトリックも AWS CloudWatch を使って取得しています。

ただ EC2 で展開しているサービスのエラーログ (PHP LOG) とかの監視が難しいです。

エラーがあったよ。くらいのアラートを飛ばすことは簡単にできるんですが、何のアラートなのかを把握することが出来ません(多分)

この辺をどうにか CloudWatch + α な修正で解消したいと思ってまとめてみたのが今回の記事の内容になります。

CloudWatch のインストール

EC2を使っていればインストールは難しくありません。↓のドキュメントがそのままになります。

docs.aws.amazon.com

サービス (EC2 側) のログを整形する

サービス側のログは↓みたいな感じにテキストでガーガー出力されています。

F, [2016-12-01T16:23:29.405110 #2634] FATAL -- :
ActionController::RoutingError (No route matches [GET] "/apple-touch-icon.png"):
  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'
  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/rack/logger.rb:38:in `call_app'
  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/rack/logger.rb:22:in `call'
  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/request_id.rb:21:in `call'
  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'
  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/runtime.rb:18:in `call'
  vendor/budnle/ruby/2.2.0/gems/activesupport-4.2.3/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/static.rb:116:in `call'
  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'
  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/engine.rb:518:in `call'
  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/application.rb:165:in `call'
  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:580:in `process_client'
  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:674:in `worker_loop'
  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:529:in `spawn_missing_workers'
  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:140:in `start'
  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/bin/unicorn_rails:209:in `<top (required)>'
  vendor/budnle/ruby/2.2.0/bin/unicorn_rails:23:in `load'
  vendor/budnle/ruby/2.2.0/bin/unicorn_rails:23:in `<main>'

CloudWatch では Log を json で出力しておくと何かと都合がいいです。

docs.aws.amazon.com

なので、このテキストログを td-agent で json に整形しましょう

<source>
  type tail
  path /var/log/hogehoge/production.log
  pos_file /var/log/td-agent/production.log.pos
  tag log.hogehoge
  format multiline
  format_firstline /^.,/
  format1 /^., \[(?<time>[^\.]+).+\][ ]+(?<severity>[^ ]+) -- :(?<message>.*)$/
  time_format %Y-%m-%dT%H:%M:%S
</source>

<match log.hogehoge>
  type file
  format json
  path /var/log/hogehoge/production.log.json
  symlink_path /var/log/hogehoge/production.log.json
  buffer_type file
  buffer_path /var/log/hogehoge/production.log.bufffer
  include_time_key true
</match>

こうすると先程のテキストログが↓のようになります

{"severity":"FATAL","message":" \nActionController::RoutingError (No route matches [GET] \"/apple-touch-icon.png\"):\n  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'\n  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'\n  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/rack/logger.rb:38:in `call_app'\n  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/rack/logger.rb:22:in `call'\n  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/request_id.rb:21:in `call'\n  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call'\n  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/runtime.rb:18:in `call'\n  vendor/budnle/ruby/2.2.0/gems/activesupport-4.2.3/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'\n  vendor/budnle/ruby/2.2.0/gems/actionpack-4.2.3/lib/action_dispatch/middleware/static.rb:116:in `call'\n  vendor/budnle/ruby/2.2.0/gems/rack-1.6.4/lib/rack/sendfile.rb:113:in `call'\n  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/engine.rb:518:in `call'\n  vendor/budnle/ruby/2.2.0/gems/railties-4.2.3/lib/rails/application.rb:165:in `call'\n  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:580:in `process_client'\n  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:674:in `worker_loop'\n  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:529:in `spawn_missing_workers'\n  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:140:in `start'\n  vendor/budnle/ruby/2.2.0/gems/unicorn-4.9.0/bin/unicorn_rails:209:in `<top (required)>'\n  vendor/budnle/ruby/2.2.0/bin/unicorn_rails:23:in `load'\n  vendor/budnle/ruby/2.2.0/bin/unicorn_rails:23:in `<main>'\n\n","time":"2016-12-01T16:23:29+09:00"}

あとはこの出力した jsonaws logs agent で cloud watch に送ります。

log_group name とかは適宜設定してください。

[/var/log/hogehoge/production.log]
datetime_format = %Y-%m-%d %H:%M:%S
file = /var/log/hogehoge/production.log.json
buffer_duration = 5000
log_stream_name = {hostname}
initial_position = end_of_file
log_group_name = /var/log/hogehoge/production.log

cloud watch にはログが json で貯まるようになりました。 f:id:sekaie:20161201174610p:plain

CloudWatch でフィルタリング

Cloud Watch には WARNING / ERROR / FATAL など複数のレベルのログがたまります。

この中で、アラートとして監視したいログをフィルタリングすることが出来ます。

この辺も CloudWatch の標準機能なのでドキュメントをみながら設定しましょう。

今回は ERROR / FATAL をフィルタしました。

f:id:sekaie:20161201175454p:plain

CloudWatch でアラート設定

フィルタしたログを今度はアラートの設定を掛けます。

これも CloudWatch の機能なので説明は割愛します。

docs.aws.amazon.com

RDSなどのメトリックと違って、ログの行数でアラートをかけるのが大きな違いかと思います。

設定はそんな難しくありません。

アラートを設定すると、はじめにの項で説明した「エラーログが出力されたよ」っていうアラートが飛ぶようになります。

ログアラートを監視出来るようにする。

ここまでは AWS CloudWatch を使った設定でしたが、ここからは AWS APIRuby を使います。

rake task になっている部分を抜粋してみました。

AWSAPIで定義してあるアラームをチェックして、ALARM状態になっていたら、そのアラートのログフィルタされているログを出力してチャットワークに出力するスクリプトです。

  desc "Monitoring"
  task :check => :environment do
    chatwork = ::Chatwork.new
    aws = ::Aws.new

    aws.alarms.each do |alarm|
      next unless alarm.state_value == 'ALARM'
      alarm_name = alarm.alarm_name
      metric_name = alarm.metric_name
      log_alarm = ::Monitoring::LogAlarm.find_by({
        alarm_name: alarm_name,
        metric_name: metric_name,
      })

      log = aws.log_events({
        log_group_name: log_alarm.log_group_name,
        filter_pattern: log_alarm.filter_pattern,
        start_time: (Time.now - 300).to_i
      }).reverse.first

      chatwork.error(log.message)
    end
  end

これを定期的に動かしておけば、アラートがなったタイミングでチャットワークに↓のようにエラー文を出力してくれるようになりました。

f:id:sekaie:20161201183456p:plain

今後の展望とかまとめ

今回は CloudWatch + αでアラートを監視する仕組みについて紹介しました。

これは自分が担当している分析基盤ツールのアラート監視には取り入れていてテスト段階ですが、これを他のサービスにも展開していきたい所存です。

あわよくばOSSあたりで開発できればいいなと思っております。

セカイエアドベントカレンダー1日目でしたー。

ほな!