sekaie engineers' blog

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

爽快!分析基盤の紹介 #2 : アクセスログ回収・集計編

おはようございます。 大阪生活5ヶ月目を迎えて体重 82 kg になりました。

ダイエットは来年から始めようかなと思ってます。どうも佐々木です。

今回はアクセスログ回収について紹介したいと思います。よろしくおねがいします。

はじめに

セカイエではエンドユーザのためのサービス renoco や、施工店やコールセンターの方の管理ツールなどが AWS でうごいています。

アクセスログは分析以外にもセキュリティの面やレスポンスタイムを使ったパフォーマンスレポートなどにも使用することが可能です。

ざっくりですが、だいたいこんな感じです。

f:id:sekaie:20151106212153p:plain

では順に説明していきましょう。

nginx の access log を ltsv format にする

nginx の access log を fluentd で扱いやすいように ltsv で出力するようにしています。

# 略
http {
    # 略
    # ltsv format
    log_format ltsv 'time:$time_iso8601\t'
                    'remote_addr:$remote_addr\t'
                    'request_method:$request_method\t'
                    'request_length:$request_length\t'
                    'request_uri:$request_uri\t'
                    'status:$status\t'
                    'bytes_sent:$bytes_sent\t'
                    'referer:$http_referer\t'
                    'useragent:$http_user_agent\t'
                    'request_time:$request_time';
    # 略
    access_log  /var/log/nginx/access.log  ltsv;
}

これで nginx の access log が ltsv で出力されるようになります。

time:2015-11-06T03:12:05+09:00  remote_addr:xx.xx.xx.xx   request_method:GET      request_length:122      request_uri:xxxxxxx     status:200      bytes_sent:247  referer:-       useragent:ELB-HealthChecker/1.0 request_time:0.000

nginx の access log を fluentd で BigQuery に送る

これができないと何も始まりません。

fluentd をインストールするのは公式のドキュメントにかかれています。

docs.fluentd.org

fluentd の BigQuery 用の plugin が gem であったのでこれを利用しています。

fluentd で nginx access logs を監視させます。

<source>
  type tail
  format ltsv
  path /var/log/nginx/xxxx_access.log
  pos_file /tmp/td-agent/nginx.access.xxxx.pos
  tag nginx.access.xxxx
</source>

<match nginx.access.xxxx>
  type bigquery
  method insert
  auth_method private_key
  email XXXXXXXX
  private_key_path /etc/td-agent/XXXXXXX

  project XXXXXXX
  dataset nginx_logs
  auto_create_table true
  table access_xxxxxx_%Y%m%d

  time_format %Y-%m-%d %H:%M:%S
  time_field time
  schema_path /etc/td-agent/schemas/xxxxxx.json
</match>

schema はこんなかんじで定義します。

[
  {
    "name": "time",
    "type": "TIMESTAMP"
  },
  {
    "name": "remote_addr",
    "type": "STRING"
  },
  {
    "name": "request_method",
    "type": "STRING"
  },
  {
    "name": "request_length",
    "type": "INTEGER"
  },
  {
    "name": "request_uri",
    "type": "STRING"
  },
  {
    "name": "status",
    "type": "INTEGER"
  },
  {
    "name": "bytes_sent",
    "type": "INTEGER"
  },
  {
    "name": "referer",
    "type": "STRING"
  },
  {
    "name": "useragent",
    "type": "STRING"
  },
  {
    "name": "request_time",
    "type": "FLOAT"
  }
]

これで td-agent を動かすと access log が big query に送信されていますので確認してみましょう。

f:id:sekaie:20151106214639p:plain

access log を使って集計

BigQuery には各サービスごとに access log table に格納されるようになりました。

このデータを使ってあれこれしてみます。

さくっと思いついた

  • response time が遅いやつをアラートに投げる
  • 404 error をアラートに投げる

あたりをやってみましょう。

  def report_slow_response # {{{
    sql = <<EOS
SELECT
  uri,
  AVG(request_time) AS avg
FROM (
  SELECT
    REGEXP_REPLACE(request_uri, '\\\\?.*$', '') AS uri,
    request_time
  FROM nginx_logs.access_#{service}_#{date}
  WHERE #{criteria}
)
GROUP BY uri
HAVING avg >= 1
ORDER BY avg DESC
EOS
# 略
  def report_not_found_page # {{{
    sql = <<EOS
SELECT
  request_uri AS uri,
  referer,
  COUNT(*) AS cnt
FROM nginx_logs.access_#{service}_#{date}
WHERE status = 404
  AND #{criteria}
GROUP BY uri, referer
ORDER BY cnt DESC
EOS
# 略

ざくっとこんなクエリを一時間おきに投げてそれをアラートとしてチャットワークに投げます。

f:id:sekaie:20151106215713p:plain

レスポンスタイムが遅いコードは見なおして改善するサイクルが出来てきました。

404 Error は不正なアタック発見やリリース後の確認などで役に立っています。

過去ログの扱いについて

nginx の access log は直近一週間分を BigQuery に残していてそれより過去分は BigQuery からは削除します。

ただ万が一に過去ログを調査するときに使用したいのでアーカイブファイルとして Google Cloud Storage にバックアップをとっています。

f:id:sekaie:20151106220253p:plain

バックアップは深夜にバックアップスクリプトが動いて cloud storage に格納しています。

おわりに

今回は nginx の access log を fluentd で回収して、パフォーマンスレポートなどの集計をしました。

今はパフォーマンスレポートを見ながらサービスのレスポンス改善を皆で取り組んでいます。

まだまだ分析基盤の一機能にすぎないのでどんどん紹介していきたいとおもいます。

ほな!