見出し画像

DuckDB + RustでAWSのログをローカル環境でサクッと分析できるCLIツールを作ってみる

はじめに

本記事は、Japan Digital Design Advent Calendar 2024 の6日目の記事になります。

三菱UFJフィナンシャル・グループ(以下MUFG)の戦略子会社であるJapan Digital Design(以下JDD)でインフラを担当している大竹です。

本記事では、DuckDB + RustでAWSのログをローカル環境で分析できるCLIツールを作ってみたのでそれについてご紹介させていただきます。

作った動機

以下の動機があり、今回ローカルでサクッとログ分析ができるCLIツールを作ってみました。

  • ALBやS3バケットのアクセスログなどインシデント対応時ぐらいしか利用しない分析基盤を維持するのは無駄な気がする

  • ログ自体は保存してあるけど分析基盤を用意してない環境で急にログ分析しなくちゃいけない状況の時に便利そう

  • 最近ログ分析で話題になっている?DuckDBを利用すればローカル環境で分析ができAthenaよりもコストが安いのでは?と考えたため

コストについては以下の条件で計算したところ1回のテーブル作成で20回以上クエリを実行するとAthenaよりもコストが安くなりそうな感じでした。

  • スキャン/ダウンロードするサイズは15GB

  • 1ファイルあたり250KB

  • 東京リージョン

DuckDBの料金
62914(ファイル数)* 0.00000037(APIのリクエスト料金/1回)+ 15(ダウンロードサイズ/GB)* 0.114(インターネットへの転送料/GB)= $1.733

Athenaの1回あたりの料金
0.0146484375(スキャンサイズ/TB)* 6(1TBあたりの料金)= $0.088

DuckDBとは

DuckDBは組み込み型のOLAP(オンライン分析処理)に特化したRDBMSで、Rustであれば以下のコマンドでアプリケーションに直接組み込むことが可能です。

cargo add duckdb --features bundled

同じくOLAPに特化したAmazon Redshiftのように大量のデータの分析・集計を高速で行うことができ、比較的データ量が大きくなりやすいログ分析に適したRDBMSになります。

なぜRustを実装しようと思ったか

前職で多少触ったことがあるのとRustはシングルバイナリでコンパイルすることが可能なのでログ分析の準備が楽になると考えたからです。(あとは趣味です)

完成したもの

完成したものはこちらになります。

こんな感じでS3バケットからcsvファイルを読み込んでテーブルを作成し、ログ分析を行うことができます。

S3 URIの指定で `*` を使うことで複数のログファイルを読み込むことができるようにしております。

# ALBアクセスログのテーブルを作成する場合
./lupe load --table-type alb --s3-uri 's3://alb-access-logs/AWSLogs/123456789012/elasticloadbalancing/ap-northeast-1/2024/**/*.log.gz'
# S3アクセスログのテーブルを作成する場合
./lupe load --table-type s3 --s3-uri 's3://s3-access-logs/123456789012/ap-northeast-1/alb/2024/11/**/*'

ログの分析

./lupe query "SELECT time, type, elb, target_processing_time, elb_status_code, target_status_code, request, request_creation_time FROM alb_logs WHERE time BETWEEN '2024-07-01' AND '2024-07-31' LIMIT 10"
+----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------+
| time                             | type | elb              | target_processing_time | elb_status_code | target_status_code | request                                      | request_creation_time         |
+===========================================================================================================================================================================================================+
| 2024-07-30T20:48:24.198924+00:00 | http | app/alb/hogehoge | -1                     | 460             | NULL               | GET http://fuga.example.com:80/fuga HTTP/1.1 | 2024-07-30T20:48:21.366+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T21:39:08.065346+00:00 | http | app/alb/hogehoge | 404.075                | 200             | 200                | GET http://fuga.example.com:80/fuga HTTP/1.1 | 2024-07-30T21:32:23.989+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T20:53:19.996885+00:00 | http | app/alb/hogehoge | -1                     | 504             | NULL               | GET http://fuga.example.com:80/fuga HTTP/1.1 | 2024-07-30T20:52:19.995+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:05:12.199472+00:00 | http | app/alb/hogehoge | 0.01                   | 502             | NULL               | GET http://fuga.example.com:80/hoge HTTP/1.1 | 2024-07-30T22:05:12.187+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:05:14.261316+00:00 | http | app/alb/hogehoge | 0.003                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:05:14.256+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:05:17.450253+00:00 | http | app/alb/hogehoge | 0.004                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:05:17.443+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:09:28.312688+00:00 | http | app/alb/hogehoge | 0.003                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:09:28.309+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:03:28.159170+00:00 | http | app/alb/hogehoge | 0.003                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:03:28.153+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:03:29.919629+00:00 | http | app/alb/hogehoge | 0.003                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:03:29.916+00:00 |
|----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------|
| 2024-07-30T22:03:30.814019+00:00 | http | app/alb/hogehoge | 0.003                  | 200             | 200                | GET http://fuga.example.com:80/say HTTP/1.1  | 2024-07-30T22:03:30.811+00:00 |
+----------------------------------+------+------------------+------------------------+-----------------+--------------------+----------------------------------------------+-------------------------------+

CLIツールの実装にあたって

テーブルの保持

実装するにあたって、S3バケットからのログファイルをダウンロードする回数をできるだけ減らせるようにすることも目標としました。
ログ分析のたびにログファイルをダウンロードしてテーブル作成すると余計な従量課金が発生してしまうためです。

上記を踏まえた実装案を2つ検討しました。

  • 作成したテーブルをファイルとしてエクポートしてテーブルを保持する

  • バックグラウンドで別プロセスを立ち上げてインメモリでテーブルを保持する

    • バックグラウンドのプロセスとはUnixドメインソケットを利用したgRPCで通信をおこなう

ローカル環境をファイルで散らかすのは好みではなかったので後者で実装することにしました。
最終的に動作フローは以下のようになりました。

ALB、S3バケットのアクセスログのDDL

最終的に下記を参考にしてDDLを作成しました。

ALBやS3バケットのアクセスログの一部フィールドでは数値として扱いたいが場合によっては文字列(`-`)が入ってしまうフィールドが存在します。(例えばALBアクセスログの `target_status_code` などです)

ターゲットから応答のステータスコード。この値は、ターゲットへの接続が確立され、ターゲットが応答を送信した場合のみ記録されます。それ以外の場合は、- に設定されます。

https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/application/load-balancer-access-logs.html#access-log-entry-format

こちらは`WITH`句と`try_cast()`を利用して数値に変換できない文字列をNULLとして扱うことで解決することができました。

CREATE TABLE <テーブル名> AS
    WITH csv_logs AS (
        SELECT * FROM read_csv(
            '<S3 URI>',
            columns={
                'type': 'VARCHAR',
                'time': 'TIMESTAMP',
                'elb': 'VARCHAR',
                'client_port': 'VARCHAR',
                'target_port': 'VARCHAR',
                'request_processing_time': 'DOUBLE',
                'target_processing_time': 'DOUBLE',
                'response_processing_time': 'DOUBLE',
                'elb_status_code': 'INTEGER',
                'target_status_code': 'VARCHAR',
                'received_bytes': 'BIGINT',
                'sent_bytes': 'BIGINT',
                'request': 'VARCHAR',
                'user_agent': 'VARCHAR',
                'ssl_cipher': 'VARCHAR',
                'ssl_protocol': 'VARCHAR',
                'target_group_arn': 'VARCHAR',
                'trace_id': 'VARCHAR',
                'domain_name': 'VARCHAR',
                'chosen_cert_arn': 'VARCHAR',
                'matched_rule_priority': 'VARCHAR',
                'request_creation_time': 'TIMESTAMP',
                'actions_executed': 'VARCHAR',
                'redirect_url': 'VARCHAR',
                'error_reason': 'VARCHAR',
                'target_port_list': 'VARCHAR',
                'target_status_code_list': 'VARCHAR',
                'classification': 'VARCHAR',
                'classification_reason': 'VARCHAR',
                'conn_trace_id': 'VARCHAR'
            },
            delim=' ',
            quote='"',
            escape='"',
            header=False,
            auto_detect=False
        )
    )
SELECT
    csv_logs.* exclude (target_status_code),
    try_cast(csv_logs.target_status_code AS INTEGER) AS target_status_code
FROM csv_logs;

またS3アクセスログのフィールド `time` がかなりの曲者でここの問題解決にかなり時間がかかりました。
`time` は時刻が `[ ]` で囲まれておりそのままではDuckDBがTIMESTAMPとしてパースできませんでした。くわえて `time` にはエスケープ処理がされてない状態で区切り文字として利用しているスペースが入っておりこちらにも悩まされました。

リクエストが受信された時間。これらの日付と時刻は協定世界時 (UTC) です。strftime() terminology を使用した形式は次のようになります: [%d/%b/%Y:%H:%M:%S %z]

https://docs.aws.amazon.com/ja_jp/AmazonS3/latest/userguide/LogFormat.html#log-record-fields

上記の問題は、一旦利用してない文字を区切り文字に指定して行全体を1つのカラムにまとめ、`regexp_extract()` で各フィールドを抽出した構造体を作成した上で `strptime()` による文字列からTIMESTAMPへの変換で対応することができました。

CREATE TABLE <テーブル名> AS
WITH parsed_logs AS (
    SELECT
        regexp_extract(col1, '^([0-9a-zA-Z]+)\s+([a-z0-9.\-]+)\s+\[([0-9/A-Za-z: +]+)\] ([^ ]+) ([^ ]+) ([^ ]+) ([^ ]+) ([^ ]+) ("[^"]*"|-) ([^ ]+) ([^ ]+) (\d+|-) (\d+|-) (\d+|-) (\d+|-) ("[^"]*"|-) ("[^"]*"|-) (\S+) (\S+) (\S+) (\S+) (\S+) (\S+) (\S+) (\S+) (\S+)(.*)$',
        [
            'bucket_owner',
            'bucket',
            'time',
            'remote_ip',
            'requester',
            'request_id',
            'operation',
            'key',
            'request_uri',
            'http_status',
            'error_code',
            'bytes_sent',
            'object_size',
            'total_time',
            'turn_around_time',
            'referrer',
            'user_agent',
            'version_id',
            'host_id',
            'signature_version',
            'cipher_suite',
            'authentication_type',
            'host_header',
            'tls_version',
            'access_point_arn',
            'acl_required'
        ]) AS log_struct
    FROM read_csv(
        '<S3 URI>',
        columns={
            'col1': 'VARCHAR'
        },
        delim='\t',
        quote='"',
        escape='"',
        header=False,
        auto_detect=False
    )
)
SELECT
    log_struct.* exclude (bytes_sent, object_size, total_time, turn_around_time),
    strptime(log_struct.time, '%d/%b/%Y:%H:%M:%S %z') AS time,
    try_cast(log_struct.bytes_sent AS INTEGER) AS bytes_sent,
    try_cast(log_struct.object_size AS INTEGER) AS object_size,
    try_cast(log_struct.total_time AS INTEGER) AS total_time,
    try_cast(log_struct.turn_around_time AS INTEGER) AS turn_around_time,
FROM parsed_logs;

さいごに

とりあえずローカル環境でALB、S3バケットのアクセスログを分析できるようにできましたが、いくつか課題が残っている状態です。

  • Windowsへの対応

    • 一応Windows 10以降ではAF_UNIXを利用できるようだがRustがまだ対応できてないため今回は見送りました

  • クエリ結果の表示

    • ARRAYやSTRUCTなどいくつかの型を利用すると結果の表示がエラーになってしまう

  • その他ログへの対応

時間ができた時に上記の課題を対応できればと思います。

最後までご覧いただきありがとうございました。


Japan Digital Design株式会社では、一緒に働いてくださる仲間を募集中です。カジュアル面談も実施しておりますので下記リンク先からお気軽にお問合せください。

この記事に関するお問い合わせはこちらにお願いします。

Technology & Development Div.
Fumiya Otake