ALBのログをEmbulk + BigQuery + Redashで可視化する

Webエンジニアの森脇です。

LCLでは、AWS ALBのアクセスログを分析し、各種KPIを定期的に確認しています。今回は、Embulk + BigQuery + Redashを利用してのログ分析の事例について紹介したいと思います。

概要

AWS ALBのアクセスログは、S3へ記録されます。S3へ記録されたログを、fluentd / Embulk を利用して Elasticsearch / BigQuery へ格納しています。

Elasticsearchは、短期的なログの解析を目的としており、Kibanaを使用して予期せぬアクセスが発生した場合の調査等に利用しています。ログは一定期間を過ぎると破棄しています。

BigQueryは、長期的なログの保存・解析を目的としており、ログは永続的に保存しています。

準備

以下の流れでやっていきます。

• ALBのアクセスログを有効化する
• BigQueryテーブル定義
• Emulbkの設定
• Redashによる可視化

ALBのアクセスログを有効化する

ALBのログはデフォルトではS3へ記録されないため、公式ドキュメントを参考に、AWS管理コンソールから設定します。

docs.aws.amazon.com

アクセスログのフォーマットは、上記ドキュメントへ記載されています。ログの末尾に、ドキュメントへ記載のないフィールドが記録される場合があります。この現象については、ドキュメントにも言及があり、末尾のフィールドは無視する必要があるようです。

アクセスログのエントリのフィールドを順に示しています。
すべてのフィールドはスペースで区切られています。
新しいフィールドが導入されると、ログエントリの最後に追加されます。
予期していなかったログエントリの最後のフィールドは無視する必要があります。

BigQueryテーブル定義

BigQueryには、ALBのログで不要なフィールドは除去して、以下のように定義しました。「backend_status_code」など本来は数値型ですが、"-"が格納される場合もあるため、文字列型として定義しています。

[
  {"name": "protocol", "type": "string", "mode": "nullable"},
  {"name": "timestamp", "type": "timestamp", "mode": "nullable"},
  {"name": "client_port", "type": "string", "mode": "nullable"},
  {"name": "backend_port", "type": "string", "mode": "nullable"},
  {"name": "request_processing_time", "type": "float", "mode": "nullable"},
  {"name": "backend_processing_time", "type": "float", "mode": "nullable"},
  {"name": "response_processing_time", "type": "float", "mode": "nullable"},
  {"name": "elb_status_code", "type": "integer", "mode": "nullable"},
  {"name": "backend_status_code", "type": "string", "mode": "nullable"},
  {"name": "received_bytes", "type": "integer", "mode": "nullable"},
  {"name": "send_bytes", "type": "integer", "mode": "nullable"},
  {"name": "request", "type": "string", "mode": "nullable"},
  {"name": "user_agent", "type": "string", "mode": "nullable"},
  {"name": "ssl_protocol", "type": "string", "mode": "nullable"},
  {"name": "trace_id", "type": "string", "mode": "nullable"},
  {"name": "domain_name", "type": "string", "mode": "nullable"},
  {"name": "matched_rule_priority", "type": "integer", "mode": "nullable"}
]

クエリでのスキャン量を抑えるために、日付毎にパーティションを分けるようにしています。これについては、後述のEmublkで設定します。

取り込み時間分割テーブルの作成と使用  |  BigQuery  |  Google Cloud

Embulkの設定

必要なplugin

• S3→Emublk
  • https://github.com/embulk/embulk-input-s3
• Embulk→BigQuery
  • https://github.com/embulk/embulk-output-bigquery
• Embulkで不要なカラムをフィルタ
  • https://github.com/sonots/embulk-filter-column

INPUT定義

guessでは正しく生成できなかったため、手動で以下を定義しました。BigQueryへ格納しないフィールドは、filterで除外するようにしています。

in:
  type: s3
  bucket: [bucket_name]
  path_prefix: [path]
  endpoint: s3-ap-northeast-1.amazonaws.com
  auth_method: instance
  skip_glacier_objects: true
  parser:
    charset: UTF-8
    newline: CRLF
    type: csv
    delimiter: ' '
    quote: ''
    escape: ''
    trim_if_not_quoted: false
    skip_header_lines: 0
    allow_extra_columns: true
    allow_optional_columns: false
    columns:
    - {name: protocol, type: string}
    - {name: timestamp, type: timestamp, format: '%Y-%m-%dT%H:%M:%S.%NZ'}
    - {name: elb, type: string}
    - {name: client_port, type: string}
    - {name: backend_port, type: string}
    - {name: request_processing_time, type: double}
    - {name: backend_processing_time, type: double}
    - {name: response_processing_time, type: double}
    - {name: elb_status_code, type: long}
    - {name: backend_status_code, type: string}
    - {name: received_bytes, type: long}
    - {name: send_bytes, type: long}
    - {name: request, type: string}
    - {name: user_agent, type: string}
    - {name: ssl_cipher, type: string}
    - {name: ssl_protocol, type: string}
    - {name: target_group_arn, type: string}
    - {name: trace_id, type: string}
    - {name: domain_name, type: string}
    - {name: chosen_cert_arn, type: string}
    - {name: matched_rule_priority, type: long}
  decoders:
  - {type: gzip}
filters:
  - type: column
    drop_columns:
      - {name: elb}
      - {name: ssl_cipher}
      - {name: target_group_arn}
      - {name: chosen_cert_arn}

OUTPUT定義

embulk-output-bigqueryプラグインは、日付分割テーブルに対応しています。「alb_logs$20180501」のように$の後ろに日付を指定します。

out:
  type: bigquery
  mode: replace
  prevent_duplicate_insert: false
  auth_method: json_key
  json_keyfile: [keyfile]
  project: [project id]
  dataset: [dataset name]
  compression: GZIP
  source_format: NEWLINE_DELIMITED_JSON
  table: [table_name]$[日付]
  schema_file: [schema_file]
  auto_create_table: true
  time_partitioning:
    type: DAY

日付の動的対応

embulkでは、定義ファイルを動的にすることが可能です。

定義ファイルの拡張子を「liquid」にします。

config.yml -> config.yml.liquid

動的にしたい箇所を以下のように書き換えます。今回の例では、テーブル名の日付部分を動的にしています。

table: {{ 'alb_logs$' | append: env.target_date }}

環境変数に日付を指定することで、変数に値を設定できます。毎日スケジューラで実行することによって、日々のALBログをBigQueryへ格納できます。

export target_date=`date +"%Y%m%d" --date "-1 day"`

この辺は、digdagというワークフローエンジンを利用するのが一般的な方法かもしれませんが、まだ詳しくは調べきれていません。

Redashによる可視化

BigQueryへ格納されたログは、 Redashで可視化しています。

BigQueryの接続定義

Redashのデータソースの定義画面から、BigQueryへの接続設定が可能です。クエリによる想定以上の課金を防ぐために、「Scanned Data Limit 」を設定しておくことをお勧めします。

SQLの作成

BigQueryでは、標準SQLとレガシーSQLが存在しますが、今後は標準SQLを利用したほうが良いでしょう。

「_PARTITIONTIME」で日付を指定することで、クエリでのスキャン量を抑えることが可能です。

SELECT
  FORMAT_TIMESTAMP("%Y%m%d", timestamp, "Asia/Tokyo") AS date,
  backend_status_code,
  COUNT(*) AS count
FROM
  `[テーブル名]`
WHERE
  _PARTITIONTIME >= "2018-05-01 00:00:00"
GROUP BY
  date,
  backend_status_code
ORDER BY
  date,
  backend_status_code

グラフの作成

LCLで作成しているグラフをいくつか紹介します。

HTTPステータスコード別の集計

HTTPステータスコードの発生数を計測し、200以外のHTTPステータスコードが意図せず増加していないかを確認します。

ページ別の平均処理時間の推移

バックエンドのの平均処理時間を計測し、パフォーマンスの悪化や、パフォーマンスチューニングの効果を確認しています。

特定ページの処理時間の分布

平均処理時間では異常値を隠してしまうため、処理時間の分布も確認しています。

Google Botのクロール分析

Google Botのユーザエージェント別にアクセス数を計測し、クロールに異常が発生していないかを確認しています。

まとめ

Embulk + BigQuery + Redashを利用したALBログの可視化の手順を紹介しました。LCLではBigQueryを利用しましたが、AWS Athenaを利用すると、S3のデータに直接クエリを発行できるため、構成としてはシンプルになりそうです。 次は、Athena + Redashでの可視化も試してみたいと思います。