クラウドワークス エンジニアブログ

日本最大級のクラウドソーシング「クラウドワークス」の開発の裏側をお届けするエンジニアブログ

AWS AthenaでALBのログを過去分も検索する

AWS SRE Terraform

こんにちは。SREチームの田中 （@kangaechu）です。リモートワークで座ってばかりの生活に危機感を感じ、昨年11月頃からランニングを始めました。最初は1キロ走っただけでヒイヒイ言っていたのですが、最近は10キロくらい走れるようになりました。運動は嫌いな方だったのですが、走るのが楽しいと思えるようになったのが一番の収穫かなと思っています。

今回はALB（Application Load Balancer）のログ検索について紹介します。

３行で説明するよ

  • AWSの公式ドキュメントの通りAthenaの設定をするとALBの過去ログが検索できない
  • 正規表現をいい感じにすることで過去ログも検索できるようになった
  • Athenaのテーブル作成、Terraformでできるよ

crowdworks.jpのシステムログ検索: Athena

システムのイベントを適宜記録し、利用状況の把握や障害時の調査、システムの改善など様々な用途で使われる重要なデータといえばログです。 ログのライフサイクルは以下の４つがあります。

  • 生成：様々なシステムが様々なフォーマット（JSONやCSV、スペース区切りなど）で生成
  • 保管：耐久性・拡張性を持つ保管に適したストレージ（S3など）で保存
  • 検索：保存したログを検索
  • 廃棄：指定した条件でアーカイブ、または廃棄

ログのライフサイクル

この中で一番複雑なのが検索です。大量のログを横断的に検索するシステムとして、以下の機能が求められます。

  • 複数のフォーマット対応： 様々なシステムで生成されたログはログ自体のフォーマットが異なるので、その差異を吸収できること
  • クエリのしやすさ：行に対する絞り込みができたり、必要な列を抽出できる機能があること。できればアプリケーションエンジニアが慣れたSQLでのクエリができること
  • 速度：（障害時など）必要なログがすぐに取得できること
  • コスト：平常時にログ検索を行わない場合、ログ検索システムの維持にコストがかからないこと

AWSではS3に保存したデータをSQLを使用して分析するマネージドサービスとして、Athenaを提供しています。 Athenaは以下の特徴があります。

  • CSV、JSON、ORC、Avro、Parquet といったさまざまなデータ形式に対応
  • 標準SQLでクエリが可能
  • クエリが自動的に並列で実行されるため、大規模なデータセットであってもクエリが早い
  • クエリでスキャンされるデータ量で課金。パーティションや列形式データセットにより、さらにコスト削減が可能

crowdworks.jp では各種ログをAthenaで検索するしくみを構築し、エンジニアは利用状況の把握や障害時の調査、システムの改善などに利用しています。

AthenaでALBのログを検索する際の課題：過去ログが検索できない

先日AthenaでALBのログを検索するために設定を行いました。 ALBのAthenaログテーブルを作成する方法はAWSのドキュメントやさまざまなブログに記載があります。

このとおりに CREATE EXTERNAL TABLE のSQLをAthenaで実行すれば完了、と思っていたのですが、過去のログを検索したところ、正しくない結果が返ってきました。

クエリ結果がnullになった

困った時はAWSの公式ドキュメント。まずはALBのログから。

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

Application Load Balancer のアクセスログ / アクセスログのエントリ

ログのエントリが増えると末尾に追加されるんですね。ふむふむ。

次にAthena。CREATE EXTERNAL TABLE には ROW FORMAT SERDE 'org.apache.hadoop.hive.serde2.RegexSerDe'を指定していたので、そのドキュメント。

Regex SerDe では、正規表現 (REGEX) を使用し、正規表現グループをテーブルの列に抽出してデータを逆シリアル化します。

データ内の行が正規表現と一致しない場合、その行内のすべての列が NULL として返されます。行が正規表現と一致するが、予想よりもグループが少ない場合、欠落しているグループは NULL です。データ内の行が正規表現と一致するが、正規表現内のグループよりも多くの列がある場合、追加の列は無視されます。

Amazon Athena - Regex SerDe

今回は データ内の行が正規表現と一致しない場合 にあたるので、パーティション化した date 以外の列は全てNULLとなりました。つらい。

ちなみにALBのログをパースするための正規表現は以下の通り。スペース区切りで各フィールドにスペースを含むとこんなにつらい正規表現が誕生するんですね。

'([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*):([0-9]*) ([^ ]*)[:-]([0-9]*) ([-.0-9]*) ([-.0-9]*) ([-.0-9]*) (|[-0-9]*) (-|[-0-9]*) ([-0-9]*) ([-0-9]*) \"([^ ]*) ([^ ]*) (- |[^ ]*)\" \"([^\"]*)\" ([A-Z0-9-]+) ([A-Za-z0-9.-]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^\"]*)\" ([-.0-9]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^ ]*)\" \"([^\s]+?)\" \"([^\s]+)\" \"([^ ]*)\" \"([^ ]*)\"')

過去ログが検索できない件の解決策：正規表現でがんばる

問題をまとめます。

  • ALBログのエントリは適宜追加される（過去のログはエントリ数が少ない）
  • AthenaではALBログのパースに正規表現を使っている
  • AthenaでALBログのパース時、正規表現に一致しないとNULLが返る

解決策は「過去ログも検索できる正規表現をがんばる」です。 追加されたエントリの有無にかかわらずマッチさせるため、昔からあるエントリ(?: 追加されたログエントリ){0,1} のような正規表現があればうまくいくはず。

その結果できた正規表現は以下の通りです。

"([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*):([0-9]*) ([^ ]*)[:-]([0-9]*) ([-.0-9]*) ([-.0-9]*) ([-.0-9]*) (|[-0-9]*) (-|[-0-9]*) ([-0-9]*) ([-0-9]*) \"([^ ]*) (.*) (- |[^ ]*)\" \"([^\"]*)\" ([A-Z0-9-_]+) ([A-Za-z0-9.-]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^\"]*)\"(?: ([-.0-9]*)(?: ([^ ]*)(?: \"([^\"]*)\"(?: \"([^\"]*)\"(?: \"([^ ]*)\"(?: \"([^s]+?)\" \"([^s]+)\"(?: \"([^ ]*)\" \"([^ ]*)\"){0,1}){0,1}){0,1}){0,1}){0,1}){0,1}){0,1}"

つらさは増しましたが、過去ログも正しくパースできるはずです。

正規表現の生成方法

crowdworks.jp では 2018年3月からのALBログが残っていました。ALBログを時期を変えて検索し、エントリが追加されたタイミングを調べたところ、以下のタイミングでエントリが追加されたことがわかりました。

  • 2018/4 追加：request_creation_time / actions_executed
  • 2018/6 追加：redirect_url
  • 2018/11 追加：lambda_error_reason
  • 2019/9 追加：target_port_list / target_status_code_list
  • 2020/7 追加：classification / classification_reason

AWSのサポートにALBのログエントリが追加された時期について質問したのですが、変更をデプロイするタイミングはALBごとに異なるため、正式な回答ができないとのことでした。

追加されたエントリごとに正規表現を増やしてもいいのですが、複雑な正規表現はパースに時間がかかりそうなので、同じ月に追加されたログエントリをひとまとめにして正規表現を作成しました。

ALBログにエントリが追加された場合、 (?: 追加されたログエントリ){0,1} を (?: (?: 追加されたログエントリ){0,1} 新たに追加されたログエントリ){0,1} のように修正すれば正しくパースできます。

Terraformでの定義方法

現状TerraformのAWSプロバイダには aws_athena_table というリソースは存在しておらず、これまでAthenaのテーブルをTerraformで作る場合は、 null_resource の local-exec から aws athena start-query-execution を実行し CREATE EXTERNAL TABLE 文を直接発行するというハックを使っていたのですが、実はAthenaのテーブルは内部的にGlueのカタログとして保存されているので、 aws_glue_catalog_table で作成できることに最近気づきました。 また、パーティション射影も projection.enabled を指定することで作成できます。

github.com

Terraformで作成したAthenaテーブルのリソースは以下の通りです。

resource "aws_glue_catalog_table" "alb_hoge" {
  database_name = "athena_database"
  name          = "alb_hoge"
  table_type    = "EXTERNAL_TABLE"
  parameters = {
    "EXTERNAL" = "TRUE"
    # データ型の指定
    # 実際はスペース区切りだが、csvで問題なかった
    # https://docs.aws.amazon.com/ja_jp/athena/latest/ug/create-table.html
    "classification"  = "csv"
    "compressionType" = "gzip"
    "typeOfData"      = "file"

    "projection.enabled" = "true"
    # 日付単位のパーティション
    # https://docs.aws.amazon.com/ja_jp/athena/latest/ug/partition-projection-supported-types.html#partition-projection-date-type
    "projection.date.type"          = "date"
    "projection.date.format"        = "yyyy/MM/dd"
    "projection.date.interval"      = "1"
    "projection.date.interval.unit" = "DAYS"
    # rangeの指定は必須なので、存在するログの日付を元に設定
    "projection.date.range" = "2018/01/01,NOW"
    # $${date}のドルが2つあるのは、Terraformのtemplatefileで変数扱いされないようにエスケープするため
    "storage.location.template" = "s3://${local.alb_hoge_log_path}/$${date}"
  }

  partition_keys {
    name = "date"
    type = "string"
  }

  storage_descriptor {
    location      = "s3://${local.alb_hoge_log_path}"
    compressed    = false
    input_format  = "org.apache.hadoop.mapred.TextInputFormat"
    output_format = "org.apache.hadoop.hive.ql.io.HiveIgnoreKeyTextOutputFormat"

    ser_de_info {
      serialization_library = "org.apache.hadoop.hive.serde2.RegexSerDe"
      parameters = {
        # 正規表現によるパース
        # https://docs.aws.amazon.com/ja_jp/athena/latest/ug/application-load-balancer-logs.html
        # https://docs.aws.amazon.com/ja_jp/athena/latest/ug/regex-serde.html
        # https://docs.aws.amazon.com/ja_jp/elasticloadbalancing/latest/application/load-balancer-access-logs.html#access-log-entry-format
        # ログの列が随時拡張されているため、サンプルの正規表現では過去のログを検索するとパースできずnullとなる。
        # そのため、拡張された列については `(:?hoge){0,1}` により、列の有無にかかわらずパースできるようにしている。
        # 月ごとでしか確認していないが、追加状況はcolumnsのコメントに記載した。
        # （AWSに確認したが、ELBの変更が適用されるタイミングは異なるので、明確な変更日はないとの回答だった）
        "input.regex"          = "([^ ]*) ([^ ]*) ([^ ]*) ([^ ]*):([0-9]*) ([^ ]*)[:-]([0-9]*) ([-.0-9]*) ([-.0-9]*) ([-.0-9]*) (|[-0-9]*) (-|[-0-9]*) ([-0-9]*) ([-0-9]*) \"([^ ]*) (.*) (- |[^ ]*)\" \"([^\"]*)\" ([A-Z0-9-_]+) ([A-Za-z0-9.-]*) ([^ ]*) \"([^\"]*)\" \"([^\"]*)\" \"([^\"]*)\"(?: ([-.0-9]*)(?: ([^ ]*)(?: \"([^\"]*)\"(?: \"([^\"]*)\"(?: \"([^ ]*)\"(?: \"([^s]+?)\" \"([^s]+)\"(?: \"([^ ]*)\" \"([^ ]*)\"){0,1}){0,1}){0,1}){0,1}){0,1}){0,1}){0,1}"
        "serialization.format" = "1"
      }
    }

    columns {
      name = "type"
      type = "string"
    }
    columns {
      name = "time"
      type = "string"
    }
    columns {
      name = "elb"
      type = "string"
    }
    columns {
      name = "client_ip"
      type = "string"
    }
    columns {
      name = "client_port"
      type = "int"
    }
    columns {
      name = "target_ip"
      type = "string"
    }
    columns {
      name = "target_port"
      type = "int"
    }
    columns {
      name = "request_processing_time"
      type = "double"
    }
    columns {
      name = "target_processing_time"
      type = "double"
    }
    columns {
      name = "response_processing_time"
      type = "double"
    }
    columns {
      name = "elb_status_code"
      type = "int"
    }
    columns {
      name = "target_status_code"
      type = "string"
    }
    columns {
      name = "received_bytes"
      type = "bigint"
    }
    columns {
      name = "sent_bytes"
      type = "bigint"
    }
    columns {
      name = "request_verb"
      type = "string"
    }
    columns {
      name = "request_url"
      type = "string"
    }
    columns {
      name = "request_proto"
      type = "string"
    }
    columns {
      name = "user_agent"
      type = "string"
    }
    columns {
      name = "ssl_cipher"
      type = "string"
    }
    columns {
      name = "ssl_protocol"
      type = "string"
    }
    columns {
      name = "target_group_arn"
      type = "string"
    }
    columns {
      name = "trace_id"
      type = "string"
    }
    columns {
      name = "domain_name"
      type = "string"
    }
    columns {
      name = "chosen_cert_arn"
      type = "string"
    }
    columns {
      name = "matched_rule_priority"
      type = "string"
    }
    # 2018/04 追加
    columns {
      name = "request_creation_time"
      type = "string"
    }
    # 2018/04 追加
    columns {
      name = "actions_executed"
      type = "string"
    }
    # 2018/06 追加
    columns {
      name = "redirect_url"
      type = "string"
    }
    # 2018/11 追加
    columns {
      name = "lambda_error_reason"
      type = "string"
    }
    # 2019/09 追加
    columns {
      name = "target_port_list"
      type = "string"
    }
    # 2019/09 追加
    columns {
      name = "target_status_code_list"
      type = "string"
    }
    # 2020/07 追加
    columns {
      name = "classification"
      type = "string"
    }
    # 2020/07 追加
    columns {
      name = "classification_reason"
      type = "string"
    }
  }
}

ログエントリが少ない過去のログであっても、正しく検索ができるようになりました。

正しく検索ができた

まとめ

ログエントリ数が少ない過去の分もすくめたALBのログをAthenaで検索する方法をご紹介しました。また、Terraformでの定義方法を紹介しました。

クラウドワークスでは様々な職種で採用を行なっています。

crowdworks.co.jp

© 2016 CrowdWorks, Inc., All rights reserved.