RedshiftでELBのアクセスログ（9千万件）を解析してみた

はじめに

AWSチームのすずきです。

AWSが提供するDWHのAmazon Redshiftを利用して、S3上に保管されたELBのアクセスログ（15万ファイル、30GB、9千万レコード）を解析する機会がありましたので、 その内容について簡単に紹介させていただきます。

参考資料

今回の作業にあたって、以下の記事を参考とさせて頂きました。

• Using Amazon Redshift to Analyze Your Elastic Load Balancer Traffic Logs
• ELB のログを Redshift で解析してみる

環境情報

• Amazon Redshiftは、東京リージョン起動済みのクラスタを利用しました。（ds1.large×1台）

一時テーブル作成

CREATE TABLE IF NOT EXISTS tmp_elb_access_log
(
request_time VARCHAR (32)
,elb VARCHAR (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 (1024)
,ssl_cipher VARCHAR (64)
,ssl_protocol VARCHAR (64)
)
;

インポート

COPY tmp_elb_access_log
FROM
's3://elb-logs-xxxxxxxx/dev/AWSLogs/nnnnnnnnnnnn/elasticloadbalancing/ap-northeast-1/'
CREDENTIALS 'aws_iam_role=arn:aws:iam::nnnnnnnnnnnn:role/redshift-role-mmmmmmmmm'
REGION 'ap-northeast-1'
delimiter ' '
ACCEPTINVCHARS REMOVEQUOTES FILLRECORD
MAXERROR AS 100000

設定内容

• S3(elb-logs-xxxxxxxx)はELBのアクセスログ出力先を指定しました
• CREDENTIALSは事前に用意したロール、またはアクセスキーを利用しました
• 参考: RedshiftのIAM Roles利用が可能となりました。
• S3,Redshiftはともに東京リージョンですが、リージョンを明示しました。（REGION 'ap-northeast-1' ）
• カラム区切りはスペースとしました（delimiter ' ' ）
• UTF8無効文字は「？」としてエラー回避しました（ACCEPTINVCHARS）
• 元データの引用符撤去しました（REMOVEQUOTES）
• カラム欠落レコード許容しました（FILLRECORD）
• エラーレコードは設定可能な最大数まで許容するとしました（AXERROR AS 100000）

確認

SELECT COUNT(1) FROM tmp_elb_access_log

解析テーブル作成

CREATE TABLE IF NOT EXISTS elb_access_log
(
request_time TIMESTAMP
,request_date_jst TIMESTAMP
,elb VARCHAR (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 (256)
,request_http_version VARCHAR (16)
,request_dir_1 VARCHAR (32)
,user_agent VARCHAR (256)
,ssl_cipher VARCHAR (64)
,ssl_protocol VARCHAR (64)
)
DISTKEY (request_time)
SORTKEY (request_date_jst, request_uri, request_dir_1, user_agent)

データ投入

INSERT INTO elb_access_log
(
SELECT
(request_time::TIMESTAMP) as request_time,
CONVERT_TIMEZONE('JST',request_time::date) as request_date_jst,
(elb::VARCHAR(64)) AS elb,
(NULLIF(SPLIT_PART(client_port, ':', 1), '-')::VARCHAR(64)) 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 AS request_processing_time,
backend_processing_time AS backend_processing_time,
response_processing_time AS response_processing_time,
(NULLIF(elb_status_code, '-')::VARCHAR(4)) AS elb_status_code,
(NULLIF(backend_status_code, '-')::VARCHAR(4)) AS backend_status_code,
received_bytes,
sent_bytes,
(NULLIF(SPLIT_PART(request, ' ', 1), '-')::VARCHAR(8)) AS request_method,
(NULLIF(SPLIT_PART(request, ' ', 2), '-')::VARCHAR(256)) AS request_uri ,
(NULLIF(SPLIT_PART(request, ' ', 3), '-')::VARCHAR(16)) AS request_http_version,
(NULLIF(SPLIT_PART(request, '/', 4), '-')::VARCHAR(8)) AS request_dir_1,
(NULLIF(user_agent, '-')::VARCHAR(256)) AS user_agent,
(NULLIF(ssl_cipher, '-')::VARCHAR(64)) AS ssl_cipher ,
(NULLIF(ssl_protocol, '-')::VARCHAR(64)) AS ssl_protocol
FROM tmp_elb_access_log
WHERE request_time ~ '[2][0-9][0-9][0-9]-[0-1][0-9]-[0-3][0-9]'
)
;

処理概要

• アクセス時刻、TIMESTAMP型に変換します
• JSTでアクセス日時をもたせました。
• 配列カラム（port、request）は分割しました。
• 異常な時刻レコードは除外します。

アクセス解析例

backend_processing_timeの発生元ベスト10

SELECT
SPLIT_PART(user_agent,'/',1) as UA
,SUM(backend_processing_time)/60/60::int AS sum_backend_time
FROM elb_access_log
WHERE request_time > SYSDATE-90
and user_agent not like 'Mozilla%'
and user_agent not like 'Zabbix%'
and user_agent not like 'Amazon%'
and user_agent not like 'Incapsula%'
and user_agent not like 'Docomo%'
and user_agent not like 'SAMSUNG%'
and user_agent not like 'Opera%'
GROUP BY SPLIT_PART(user_agent,'/',1)
ORDER BY sum_backend_time desc
LIMIT 10

• ヘルスチェック、通常ブラウザからのアクセスは除外しました。

backend_processing_timeの発生先ベスト10

SELECT
request_uri
,(SUM(backend_processing_time)/60/60)::int AS sum_backend_time
FROM elb_access_log
WHERE request_time > SYSDATE-90
and request_dir_1 not in ('category','feed')
and request_uri != 'https://dev.classmethod.jp:80/'
GROUP BY request_uri
ORDER BY sum_backend_time desc
LIMIT 10

• 記事ページのみ対象としました

考察

• 公開直後、参照が集中する記事についてはキャッシュ経由の配信となりますが、ロングテールで、一定の需要が存在する記事がキャッシュの乗りが悪く、サーバ負荷になっている事が伺えました。

• 上記レスポンスタイムは、GoogleAnalyticsなどでも確認が可能ですが、サーバのレスポンスコードなどを組み合わせた解析や、全量ログを前提とした抽出にはRedshiftは大きな効果を発揮すると考えられます。

まとめ

今回、利用したRedshiftクラスタは、ds1.large、1台の最小構成でした。 USリージョンであれば1時間0.2$、EC2のc4.xlargeと同等の単価で利用ができる環境ですが、 S3からのインポート（COPY）、所要時間は20分程。一時テーブルが消費した容量は5GB強でした。

Redshiftに展開された約9000万レコードの解析、、先述のクエリの所要時間は30〜40秒。 充分な性能であったため、最適化などは未実施でしたが、 適切なキー設定やデータの最適化などで更なる高速化が期待できる状態でした。

SQLを利用した柔軟な解析、手軽に実施できるRedshift、ELBのアクセスログ解析にも有効でした。 ログ確認や活用などの手段として、是非ご活用ください。