はじめに

Redshift で遊んでみたいものの、データがないとはじまりません。そこで、AWS の中でも利用頻度の高い ELB のアクセスログを解析対象データとして活用してみたいと思います。

前提

本稿は以下の知識を前提に進めます。セットアップ方法がわからない方は別途、他の資料をあたってください。

Redshift のクラスタ起動方法
Redshift クライアントのセットアップ方法
ELB、および Web サーバのセットアップ方法

ELB アクセスログの有効化

まずは ELB を作成してアクセスログを有効化しましょう。バックエンドの EC2 は適当に apache、nginx あたりを起動しときましょう。しばらくしたら、S3 にログがたまってるはずなので、確認できたらログはOKです。

Redshift のテーブル定義

次に、アクセスログのフォーマットを確認しましょう。¹これを元に Redshift のテーブルを定義します。ETL 的な考え方で、まず、S3 からアクセスログデータを引っ張ってきて、それを一時テーブルにロードします(Extraction)。そのあと、一時テーブルから変換して本テーブルにロードします(Transform)。Transform 処理は凝りだすといろいろできそうですが、ここでは、request_time をまずは文字列としてロードして、そのあと TIMESTAMP 型としてロードしてみようと思います。ELB のアクセスログはマイクロセカンドまで記録されていますが、Redshift の TIMESTAMP 型は YYYY-MM-DD HH24:MI:SS のフォーマットである必要があります。データ型のサイズは割りと適当なので、ロード時にエラーになったら stl_load_errors テーブルにログがあるはずなので適宜、err_reason を参考に修正してください。

-- 降順に並べて10件取得
select err_reason from stl_load_errors order by starttime desc limit 10;

-- 一時テーブル
create table elb_access_log_tmp
(
  request_time  CHAR(32),
  elb   CHAR(64),
  client_port   VARCHAR(32),
  backend_port  VARCHAR(32),
  request_processing_time   FLOAT,
  backend_processing_time   FLOAT,
  response_processing_time  FLOAT,
  elb_status_code     VARCHAR(4),
  backend_status_code VARCHAR(4),
  received_bytes  BIGINT,
  sent_bytes      BIGINT,
  request         VARCHAR(2048),
  user_agent      VARCHAR(256),
  ssl_cipher      VARCHAR(64),
  ssl_protocol    VARCHAR(64)
);

-- 本テーブル
create table elb_access_log
(
  request_time  TIMESTAMP,
  request_time_nano_sec INTEGER,
  elb   CHAR(64),
  client_ip     VARCHAR(64),
  client_port   INTEGER,
  backend_ip    VARCHAR(64),
  backend_port  INTEGER,
  request_processing_time   FLOAT,
  backend_processing_time   FLOAT,
  response_processing_time  FLOAT,
  elb_status_code     VARCHAR(4),
  backend_status_code VARCHAR(4),
  received_bytes  BIGINT,
  sent_bytes      BIGINT,
  request_method        VARCHAR(8),
  request_uri           VARCHAR(2048),
  request_http_version  VARCHAR(16),
  user_agent      VARCHAR(256),
  ssl_cipher      VARCHAR(64),
  ssl_protocol    VARCHAR(64)
);

データ読み込み

さて、いよいよデータをロードします。まずは手順をおさらいしましょう。
1. S3 にたまっているアクセスログから Redshift の一時テーブル elb_access_log_tmp にロードする
2. 一時テーブル elb_access_log_tmp から変換処理をしつつ本テーブル elb_access_log にロードする

1 では COPY コマンド、2 では SELECT and INSERT で実現します。今回は Redshift のみで処理が簡潔していますが、Extraction、Transfrom を EMR など別のサービスで処理してもいいかもしれません。

S3 から一時テーブルにロード

COPY コマンドを以下になります。

COPY elb_access_log_tmp
FROM 's3://elb-access-log-xxxxxxx/AWSLogs/xxxxxxx/elasticloadbalancing/ap-northeast-1/2015/07/10/'
CREDENTIALS 'aws_access_key_id=xxxx;aws_secret_access_key=xxxx'
REGION 'ap-northeast-1'
DELIMITER AS ' '
REMOVEQUOTES;

DELIMITER : アクセスログのフォーマットは半角空白区切りなので DELIMITER として ' ' を指定します
REMOVEQUOTES : request 項目はダブルクオーテーションで括られているのでロード時に削除します。
REGION : S3 のバケットが Redshift と別リージョンにある場合は明示的に指定しましょう。

ELB のアクセスログはフォルダを切ってくれるのでロードしやすいですね。COPYコマンドについてはこちらを参考にしましょう。

一時テーブルから本テーブルにロード

さて、一時テーブルにロードできたらとりあえず10件ほど中身をみてみましょう。Redshift は列指向 DB のため、本当は * で指定するのはよくないのですが、サボってます。。データ量が少ないときは大した影響はないでしょうが、何百GBもあるテーブルを SELECT するときは気をつけましょう。

select * from elb_access_log_tmp limit 10;

問題がないようでしたら、本テーブルへロードします。SELECT and INSERT クエリは以下のようになります。

INSERT INTO elb_access_log
(
  SELECT
    SUBSTRING(request_time,0,20)::TIMESTAMP AS request_time,
    SUBSTRING(request_time,21,6)::INTEGER AS request_time_micro_sec,
    elb,
    NULLIF(SPLIT_PART(client_port, ':', 1), '-') AS client_ip,
    NULLIF(SPLIT_PART(client_port, ':', 2), '-')::INTEGER AS client_port,
    case backend_port when '-' then NULL else SPLIT_PART(backend_port, ':', 1) end AS backend_ip,
    case backend_port when '-' then NULL else SPLIT_PART(backend_port, ':', 2)::INTEGER end AS backend_port,
    request_processing_time,
    backend_processing_time,
    response_processing_time,
    NULLIF(elb_status_code, '-'),
    NULLIF(backend_status_code, '-'),
    received_bytes,
    sent_bytes,
    NULLIF(SPLIT_PART(request, ' ', 1), '-'),
    NULLIF(SPLIT_PART(request, ' ', 2), '-'),
    NULLIF(SPLIT_PART(request, ' ', 3), '-'),
    NULLIF(user_agent, '-'),
    NULLIF(ssl_cipher, '-'),
    NULLIF(ssl_protocol, '-')
  FROM elb_access_log_tmp
);

一部、関数を入れ子にしたり CAST していてややこしいかもしれませんので、補足します。

CAST
request_time を例に説明します。元は文字列ですが、それを TIMESTAMP 型に変換する必要があります。そのため、::TIMESTAMP を省略すると TIMESTAMP 型に文字列型をセットしようとして以下のようなエラーになります。エラーが親切なのでわかりやすいです。CAST の詳細はこちら。
```
ERROR:  column "request_time" is of type timestamp without time zone but expression is of type text
HINT:  You will need to rewrite or cast the expression.
```
SUBSTRING
request_time は "2015-05-13T23:39:43.945958Z" のような書式で micro second まで記録されていますので、そのままでは TIMESTAMP 型にセットできません。そこで、"." で区切って YYYY-MM-DD HH24:MI:SS の部分とカンマ秒以下を分割してテーブルにセットしてみました。SUBSTRING ではなく次に説明する SPLIT_PART で "." で分割してもよかったのですが、それだとカンマ秒以下に含まれる "Z" を省く処理をかまさないといけないのでここでは SUBSTRING で処理してみました。SUBSTRING の詳細はこちら。
SPLIT_PART
client 側の接続時の Port 番号はリクエストごとに変わるので client_port は集計の都合上、IP Address と Port番号に分けたいところです。そこで、SPLIT_PART を利用して ":" で分割しました。SPLIT_PART の詳細はこちら。
NULLIF
ELB アクセスログでは記録されない項目が "-" とハイフンとなっており、このまま格納してもよいのですが、まあ無駄なので NULL をセットするようにしてみました。NULLIF の詳細はこちら。

ここでのやり方はあくまで一例ですので、別の関数を使用しても OK です。ぜひドキュメントを参考にもっとイケてるやり方を探ってみてください。

ソートキー、分散スタイル、圧縮

以上の手順だけでも動きますが、より運用に耐えうる設計をするためにチュートリアルを参考にテーブルをチューニングしましょう。重要なテーマですが、とりあえずはチューニングしなくても動くので本稿では触れずにおきます。参考リンクだけあげておきます。

解析

クエリ例をいくつかご紹介しましょう。

リクエスト時間で絞込
TIMESTAMP 型に変換したので、その恩恵が受けられます。ソートキーを指定しないと順序がバラバラにデータが格納されますが、TIMESTAMP 型であれば order by をすることで時系列にソートして SELECT できます。ソートキーを指定した場合とそうでない場合でどれくらいパフォーマンスが変わるか比較してみるとソートキーのありがたみが実感できると思います。
```
select *
from elb_access_log
where request_time between '2015-07-10 12:00:00' and '2015-07-12 15:00:00'
order by request_time;
```

client_ip, request_method, elb_status_code, backend_status_code ごとに集計
特定クライアントが多量にアクセスしてないか可視化できます。

select client_ip, request_method, elb_status_code, backend_status_code, count(*) AS count
from elb_access_log
where request_time between '2015-07-10 12:00:00' and '2015-07-12 15:00:00'
group by client_ip, request_method, elb_status_code, backend_status_code
order by client_ip;

backend_ip, request_method, elb_status_code, backend_status_code ごとに集計
特定のバックエンドに処理に偏りがあるかチェックできます。

select backend_ip, request_method, elb_status_code, backend_status_code, count(*) AS count
from elb_access_log
where request_time between '2015-07-10 12:00:00' and '2015-07-12 15:00:00'
group by backend_ip, request_method, elb_status_code, backend_status_code
order by backend_ip, elb_status_code;

アクセスランキング Top 10
アクセスランキングも簡単に確認できます。

select request_uri, request_method, elb_status_code, backend_status_code, count(*) AS count
from elb_access_log
where request_time between '2015-07-10 12:00:00' and '2015-07-12 15:00:00'
group by request_uri, request_method, elb_status_code, backend_status_code
order by count desc
limit 10;

おわりに

いかがでしょうか。Redshift を使えば、簡単に ELB のアクセスログを解析可能なことが実感いただけたかと思います。運用にあたっては、S3 からロードして解析できる状態にするまでの工程を自動化すべきですが、本稿では手動での説明に留めます。コードで実装するのもそれほど難易度は高くないと思いますので、ぜひチャレンジしてみてください。
ちなみに、同じテーマですでに AWS 公式のブログにエントリーがありますが、一時テーブルをかませて ETL 処理後に本テーブルにロードすることでより細かいクエリを投げられるようにしたのが本稿になります。
また、解析にあたっては Redshift 以外に AWS の EMR、 Google の BigQuery、TreasureData なども選択肢としてありえるかと思います。それぞれの費用、開発・運用コスト、性能等の観点からユースケース別に最適なサービスをまとめてみるのもおもしろそうです。

ちなみに、日本語ドキュメントは古いので危険です。積極的に英語版を参照しましょう。 ↩

ELB のログを Redshift で解析してみる