Amazon Athena RegexSerDe を利用して ALB ログを探索する

eyecatch_athena

先日に引き続き、Amazon Athena RegexSerDe を利用して ALB / ELB v2 (Application Load Balancer / Elastic Load Balancing Version 2)のログを Amazon Athena で探索する方法を紹介します。

ALB / ELB v2 とは

2016年8月にL7の機能が強化された ALB(Application Load Balancer)がリリースされました。現在は、ELB のVersion1 が CLB(Classic Load Balancer)、ELB のVersion2 が ALB(Application Load Balancer)をそれぞれ意味します。

参考:【新機能】新しいロードバランサー Application Load Balancer(ALB)が発表されました

ALB は、ロードバランサーに送信されるリクエストまたは接続について、詳細情報を収集するアクセスログをキャプチャし、圧縮ファイルとして指定した Amazon S3 バケット内に保存します。各ログには、リクエストまたは接続を受け取った時刻、クライアントの IP アドレス、レイテンシー、リクエストのパス、サーバーレスポンスなどの情報が含まれます。これらのアクセスログを使用して、トラフィックパターンの分析や、問題のトラブルシューティングを行うことができます。なお、ALB のアクセスログを有効にするには、アクセスログの有効化 (Application Load Balancer) を御覧ください。

以降、このアクセスログファイルに対して、Amazon Athena のテーブル定義とログの探索をご紹介します。

ALBのアクセスログ

各ログエントリには、ロードバランサーに対する 1 件のリクエストの詳細が含まれます。ログエントリのすべてのフィールドはスペースで区切られています。ログファイルの各エントリは次の形式になります。

type timestamp elb_name client_addrport target_addrport request_processing_time target_processing_time response_processing_time elb_status_code target_status_code received_bytes sent_bytes "request" "user_agent" ssl_cipher ssl_protocol target_group_arn trace_id

様々なアクセスログエントリを確認したいので、ALBのマニュアルアクセスログのエントリの例から引用しました。

http 2016-08-10T21:00:00.000000Z app/my-loadbalancer/50dc6c495c0c9188 192.168.131.39:2817 - 0.0000 0.001 0.0000 200 200 34 366 "GET http://www.example.com:80/ HTTP/1.1" "curl/7.46.0" - - arn:aws:elasticloadbalancing:us-east-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337262-36d228ad5d99923122bbe354"
http 2016-08-10T22:08:42.945958Z app/my-loadbalancer/50dc6c495c0c9188 192.168.131.39:2817 10.0.0.1:80 0.0000 0.001 0.0000 200 200 34 366 "GET http://www.example.com:80/ HTTP/1.1" "curl/7.46.0" - - arn:aws:elasticloadbalancing:us-east-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337262-36d228ad5d99923122bbe354"
https 2016-08-10T23:39:43.065466Z app/my-loadbalancer/50dc6c495c0c9188 192.168.131.39:2817 10.0.0.1:80 0.000086 0.001048 0.001337 200 200 0 57 "GET https://www.example.com:443/ HTTP/1.1" "curl/7.46.0" ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 arn:aws:elasticloadbalancing:us-east-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337281-1d84f3d73c47ec4e58577259"
h2 2016-08-10T00:10:33.145057Z app/my-loadbalancer/50dc6c495c0c9188 10.0.1.252:48160 10.0.0.66:9000 0.000 0.002 0.000 200 200 5 257 "GET https://10.0.2.105:773/ HTTP/2.0" "curl/7.46.0" ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 arn:aws:elasticloadbalancing:us-east-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337327-72bd00b0343d75b906739c42"
ws 2016-08-10T00:32:08.923954Z app/my-loadbalancer/50dc6c495c0c9188 10.0.0.140:40914 10.0.1.192:8010 0.001 0.003 0.000 101 101 218 587 "GET http://10.0.0.30:80/ HTTP/1.1" "-" - - arn:aws:elasticloadbalancing:us-east-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337364-23a8c76965a2ef7629b185e3"
wss 2016-08-10T00:42:46.423695Z app/my-loadbalancer/50dc6c495c0c9188 10.0.0.140:44244 10.0.0.171:8010 0.000 0.001 0.000 101 101 218 786 "GET https://10.0.0.30:443/ HTTP/1.1" "-" ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 arn:aws:elasticloadbalancing:us-west-2:123456789012:targetgroup/my-targets/73e2d6bc24d8a067 "Root=1-58337364-23a8c76965a2ef7629b185e3"

テーブル定義

上記のログファイルのフィールドを、以下の様にテーブルのカラムにマッピングしています。ALB が target の EC2インスタンスと通信できない場合もクエリできるようにマッピングしています。

フィールド 説明
type リクエストまたは接続のタイプ。有効な値は次のとおりです (その他の値は無視してください)。

  • http — HTTP
  • https — HTTP over SSL/TLS
  • h2 — HTTP/2 over SSL/TLS
  • ws — WebSockets
  • wss — WebSockets over SSL/TLS
request_timestamp ロードバランサーがクライアントからリクエストを受け取った時刻 (ISO 8601 形式)。WebSocket の場合、これは接続を閉じる時間です。
elb_name ロードバランサーのリソース ID。アクセスログエントリを解析する場合、リソース ID にはスラッシュ (/) を含めることができます。
client_addrport リクエストを送信したクライアントの IP アドレスとポート。
client_ip リクエストを送信したクライアントの IP アドレス。
client_port リクエストを送信したクライアントのポート。
target_addrport このリクエストを処理したターゲットの IP アドレスとポート。

クライアントがリクエスト全体を送信しなかった場合、ロードバランサーはターゲットにリクエストをディスパッチできず、この値が - に設定されます。

target_ip このリクエストを処理したターゲットの IP アドレス。

クライアントがリクエスト全体を送信しなかった場合、ロードバランサーはターゲットにリクエストをディスパッチできず、この値が null に設定されます。

target_port このリクエストを処理したターゲットのポート。

クライアントがリクエスト全体を送信しなかった場合、ロードバランサーはターゲットにリクエストをディスパッチできず、この値が null に設定されます。

request_processing_time ロードバランサーがリクエストを受け取った時点からターゲットに送信するまでの合計経過時間 (秒単位)。

ロードバランサーがリクエストをターゲットにディスパッチできない場合、この値は -1 に設定されます。この状況が発生するのは、ターゲットがアイドルタイムアウト前に接続を閉じた場合か、クライアントが誤った形式のリクエストを送信した場合です。

target_processing_time ロードバランサーがターゲットにリクエストを送信した時点から、そのターゲットが応答ヘッダーの送信を開始した時点までの合計経過時間 (秒単位)。

ロードバランサーがリクエストをターゲットにディスパッチできない場合、この値は -1 に設定されます。この状況が発生するのは、ターゲットがアイドルタイムアウト前に接続を閉じた場合か、クライアントが誤った形式のリクエストを送信した場合です。

response_processing_time ロードバランサーがターゲットから応答ヘッダーを受け取った時点から、クライアントへの応答の送信を開始した時点までの合計経過時間 (秒単位)。これには、ロードバランサーでの待機時間と、ロードバランサーからターゲットへの接続の取得時間の両方が含まれます。

ロードバランサーがリクエストをターゲットに送信できない場合、この値は -1 に設定されます。この状況が発生するのは、ターゲットがアイドルタイムアウト前に接続を閉じた場合か、クライアントが誤った形式のリクエストを送信した場合です。

elb_status_code ロードバランサーからの応答のステータスコード。
target_status_code ターゲットから応答のステータスコード。この値は、ターゲットへの接続が確立され、ターゲットが応答を送信した場合のみ記録されます。それ以外の場合、値は - に設定されます。
received_bytes クライアント (リクエスタ) から受け取ったリクエストのサイズ(バイト単位)。HTTP リクエストの場合、これにはヘッダーが含まれます。WebSocket の場合、これは接続でクライアントから受信した合計バイト数です。
sent_bytes クライアント (リクエスタ) に返される応答のサイズ(バイト単位)。HTTP リクエストの場合、これにはヘッダーが含まれます。WebSocket の場合、これは接続でクライアントに送信した合計バイト数です。
request クライアントからのリクエスト行は二重引用符で囲まれており、次の形式を使用してログに記録されます。HTTP メソッド + プロトコル://ホスト:ポート/uri + HTTP バージョン。
user_agent リクエスト元のクライアントを特定する User-Agent 文字列。この文字列は、1 つ以上の製品 ID (製品[/バージョン]) から構成されます。文字列が 8 KB より長い場合は切り捨てられます。
ssl_cipher [HTTPS リスナー] SSL 暗号。正常なネゴシエーションの後に受信 接続が確立した場合にのみ、この値が記録されます。それ以外の場合、値は - に設定されます。
ssl_protocol [HTTPS リスナー] SSL プロトコル。正常なネゴシエーションの後に受信 接続が確立した場合にのみ、この値が記録されます。それ以外の場合、値は - に設定されます。
target_group_arn ターゲットグループの Amazon リソースネーム (ARN)。
trace_id [X-Amzn-Trace-Id] ヘッダーのコンテンツです。

では、これらを順にカラムとして定義します。Amazon Athena は、ログが複数のファイルの場合でも、同じフォルダに配置することで同じテーブル内のデータとしてクエリーを実行できます。

CREATE EXTERNAL TABLE IF NOT EXISTS alb_logs (
type string,
request_timestamp string,
elb_name string,
client_addrport string,
client_ip string,
client_port int,
target_addrport string,
target_ip string,
target_port int,
request_processing_time decimal(8,6),
target_processing_time decimal(8,6),
response_processing_time decimal(8,6),
elb_status_code string,
target_status_code string,
received_bytes int,
sent_bytes int,
request string,
user_agent string,
ssl_cipher string,
ssl_protocol string,
target_group_arn string,
trace_id string
)
ROW FORMAT SERDE 'org.apache.hadoop.hive.serde2.RegexSerDe'
WITH SERDEPROPERTIES (
  'serialization.format' = '1',
  'input.regex' = '([^ ]*) ([^ ]*) ([^ ]*) (([^ ]*):([^ ]*)|-) (([^ ]*):([^ ]*)|-) ([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*) (\\"[^\\"]*\\") (\\"[^\\"]*\\") ([^ ]*) ([^ ]*) ([^ ]*) (\\"[^\\"]*\\")[ ]*$'
) 
LOCATION 's3://devio2017-handson/07-alblogs/2016/08/10/'
TBLPROPERTIES ('has_encrypted_data'='false');

上記のDDLをテンプレートとして利用する場合、LOCATION に指定するクエリ対象のロフファイルを保存している S3バケット/フォルダ名を変更するだけで、再利用できます。

全てのレコードの全てのカラムデータが参照できることが確認できます。

20170726-alblogs-all

ALB ログを探索

CLB ログを探索 と同じように探索可能です。(SQLの backend_status_codetarget_status_code に書き換えて実行してください)

ALB ログと CLB ログを横断的に探索したい場合

ALB と CLB を一元的に状況把握したい場合や、CLB から ALB に加重ラウンドロビンで徐々に移行する過程を監視したい場合など、ALB ログと CLB ログを横断的に探索するには、以下のようにフィールドを一致することで一元的に監視ができます。

SELECT * FROM (
SELECT 
'clb' as elb_type,
'-' as type,
request_timestamp,
elb_name,
client_addrport,
client_ip,
client_port,
backend_addrport as target_addrport,
backend_ip as target_ip,
backend_port as target_port,
request_processing_time,
backend_processing_time,
response_processing_time,
elb_status_code,
backend_status_code as target_status_code,
received_bytes,
sent_bytes,
request,
user_agent,
ssl_cipher,
ssl_protocol,
'-' as target_group_arn,
'-' as trace_id
FROM clb_logs
UNION ALL
SELECT 
'alb' as elb_type,
type,
request_timestamp,
elb_name,
client_addrport,
client_ip,
client_port,
target_addrport,
target_ip,
target_port,
request_processing_time,
target_processing_time,
response_processing_time,
elb_status_code,
target_status_code,
received_bytes,
sent_bytes,
request,
user_agent,
ssl_cipher,
ssl_protocol,
target_group_arn,
trace_id
FROM alb_logs
)
ORDER BY 3;

実行すると以下の通りです。

20170726-alblogs-unionall

ALB のログを簡単に「速く」「安く」探索するには

ログファイルの検索範囲を限定する

ALBのログは、デフォルトで年月日の階層的なフォルダ構成になっていますので、簡単に期間を限定できます。 例えば、

  • 2017年1月1日の場合: s3://<logbacket and folder>/2017/01/01/
  • 2017年1月の場合: s3://<logbacket and folder>/2017/01/
  • 2017年の場合: s3://<logbacket and folder>/2017/

探索範囲のスコープが明らかな場合は、利用費の削減や応答時間の短縮の観点から探索するログの期間を限定することをおすすめします。

パーティション設定する

ALBのログのフォルダ名や階層は決まっているので、「カラム名なしパーティション」として、パーティションを設定します。上記のテーブル定義に PARTITIONED BY (year int, month int, day int) を追加して、テーブルを再作成した後、ログの検索範囲のパーティションを追加します。恒久的にテーブルを定義して、常ににログを監視したい場合は、パーテイション設定することもご検討ください。パーティションの設定は Scenario 2: Data is not partitioned を御覧ください。

その他

読み込むファイルサイズを小さくするためデータの圧縮がベターですが、ALBのログファイルが既にgzip圧縮済みですのでそのままで構いません。その他、ファイルサイズの最適化やカラムナフォーマットへの変換については、必要に応じて検討してください。

最後に

ALB は インスタンスをターゲットグループというグループでまとめてロードバランサに登録しますので、target_group_arn によってグルーピングして粒度の細かい分析が可能になります。また、trace_id の項目が追加されて、クライアントからのターゲットまたは他のサービスへの HTTP リクエストをトレースできるようになります。

現状は、CLB(ELB v1)が主流ですが、今後の新規案件は ALB(ELB v2)になることが予想されますので、Amazon Athenaで ALB のログを検索して、課題解決できることを期待しています。

関連ブログ: Amazon Athena RegexSerDe を利用して CLB ログ / Apache Web のアクセスログを探索する

AWS Cloud Roadshow 2017 福岡