【ログ分離】 ログデータを DB に保存してはいけません

はじめに

TROCCO では ETL ジョブや、dbt 連携、ワークフローなど、様々なジョブで実行ログをリアルタイムで見ることができます。
これによりエラー時のトラブルシュートをスムーズに行うことができます。

そして、この実行ログですが、DB にあるジョブのレコードの1カラムに書き込まれていました。

このように TROCCO の実行ログの表示機能は、データベースのアンチパターンの上に成り立っています。
ログデータは TEXT 型で DB に保存されているためサイズが大きく、また TROCCO の成長に応じてジョブ数は増えるため、ログデータもサービスの成長とともに無限に成長してしまいます。
おかげさまでアカウント数は増加の一方であり、それに伴い DDL が遅くなったり、また SELECT のパフォーマンスも当然落ちるため、INDEX に気をつけたりする必要がありました。

SRE ではこれに課題感を持ち、ログを DB から分離する工事を行っています。

ログデータについて

0.6MB になるようなデータが保存されていることもあります。
また冒頭でも触れた通り、ジョブは刻一刻と増えており、それだけログデータも日々作成されています。
ログを DB から剥がすプロジェクトの事前調査の時点では、ジョブは1日に16万レコードほど作成されていました。

このようなクソデカなレコードを抱え、かつ日に16万ずつレコードが増加するテーブルへのクエリは、かなりリスクのあるものとなっています。
具体的には以下のようなものがあります。

• DDL が遅い
• SELECT が負荷、遅い
• Buffer Pool Size (メモリ) の量が減る
• Aurora の I/O が減る

実装面での技術的負債

アーキテクチャレベルで大きいデータを DB に保存している課題に加え、実装面でもログ出力のロジックに課題があったためリファクタも行いました。
これまでの歴史的経緯により、ログの出力処理のロジックはジョブごとの差異はほとんどないにも関わらず、ジョブごとに実装方法に揺れがありました。

アーキテクチャの刷新に伴い、このような実装面での負債についても整理を行いました。
そして以下のようにシンプルになるようリファクタリングをしています。

リアーキテクチャ

ログの保存先として S3 を採用し、DB をまるっと置き換えるアーキテクチャを採用しました。
TEXT 型でなく BLOB を使うことでアーキテクチャの変更が不要になりますが、Aurora の IO コストが毎月数十万円以上かかり肥大化し無視できないため、保存先に S3 を採用しました。

データストアについて

1つあたりのログデータが大きく、プロダクトのスケールとともにデータ量が増えるため、それに対応できるデータストアを検討しました。

• DynamoDB
• DocumentDB
• S3

DynamoDB

1度に大きなデータを扱う処理が難しそうだったため見送りました。
保存できる文字列のサイズが 400KB に制限されていたり、データの読み取り (Scan) にも 1MB の制限があったりします。

DocumentDB

ログデータを扱うという意味では、比較対象の中では最も実装コストなどを鑑みて良い選択肢ではありました。
SQL ライクな構文を利用できるため、アプリケーションのロジックの修正も大きく変える必要がないのも良い点でした。
ただ、料金が高く、それなりのインスタンスサイズでマルチAZの構成を組むとなると、ログを分離したことによる追加のコストが無視できないものとなってしまうことが予想されました。

S3

料金と運用コストの低さが魅力であったため、ログの保存先として採用しました。
他のサービスと比べて安価でインフラを考えずに運用できる点が大きかったです。
一方で、ファイルストレージであるため、SQL のように UPDATE 文のようなログの追記などができず、ログを複数ファイルとして扱う必要があるため、アプリケーションロジック側でなんとかしないといけない点が多いことがデメリットとしては考えられました。

ログの転送

TROCCO のジョブを処理するコンテナを K8s Job で管理していますが、そこにサイドカーとして Vector をデプロイする形でログの転送を実現しました。

転送方法

最終的にサイドカーパターンと Vector を組み合わせてログを転送していますが、他にも選択肢として考慮していました。

• 自前で実装し S3 へログを直接転送
• サイドカーパターン
  • fluentbit
  • Logstash
  • Fluentd
  • Vector

アプリケーションから S3 へ直接転送

SDK を利用する方法です。
アプリケーションの実装のみで、追加でログ転送のためのコンポーネントを管理する必要がなくなります。
とは言え、データ転送を行うソフトウェアが成熟しているなか、自力で転送処理を実装してコードを保守していく点は効率が悪い選択と言えます。
ファイルを逐一 SDK で転送するわけにもいかないので、バッファ処理を考えたり、SDK の例外処理を考えたりとハードルが結構高いので見送りました。

fluentbit

ローカルにあるログファイルの読み込みを tail で行うことができなかったため見送りました。
Fluent-bit input plugin tail doesn't process all logs: scan_blog add(): dismissed: · Issue #4155 · fluent/fluent-bit
当初は fluentbit を利用する想定ではいましたが、このバグに遭遇したうえ、ログ転送ツールを比較する中で Vector を知ったのが大きかったです。

当時検証で利用したマニフェスト (S3 は LocalStack で再現)

LocalStack

apiVersion: v1
kind: Pod
metadata:
  name: fluent-bit
spec:
  containers:
    - name: ubuntu
      image: ubuntu:22.04
      command: [ "/bin/sh" ]
      args: [ "-c", "while true; do echo $(date) hello >> /var/log/stdout.log; sleep 2; done" ]
      volumeMounts:
        - name: logs
          mountPath: /var/log
    - name: fluent-bit
      image: public.ecr.aws/aws-observability/aws-for-fluent-bit:2.31.12.20230821
      env:
        - name: AWS_REGION
          value: us-west-2
        - name: AWS_ACCESS_KEY_ID
          value: dummy
        - name: AWS_SECRET_ACCESS_KEY
          value: dummy
      volumeMounts:
        - name: fluent-bit-config
          mountPath: /fluent-bit/etc/
        - name: logs
          mountPath: /var/log
  volumes:
    - name: fluent-bit-config
      configMap:
        name: fluent-bit-config
    - name: logs
      emptyDir: {}
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: fluent-bit-config
data:
  fluent-bit.conf: |-
    [SERVICE]
        storage.path  /var/fluent-bit/state/flb-storage/
        Log_Level     trace
    [INPUT]
        Name              tail
        Path              /var/log/stdout.log
        Path_Key          filePath
        tag               test-job-1
        Refresh_Interval  30
        DB                /var/fluent-bit/state/flb_stdout.db
        Read_from_Head    Off
    [OUTPUT]
        Name s3
        Match *
        bucket stdout.log.test.trocco.io
        endpoint http://10.0.1.20:4566
        s3_key_format /stdout.log
        s3_key_format_tag_delimiters -

Logstash

Java で実装されていることもあり、ログを転送するという簡単な処理の割にメモリリソースを食ってしまうため見送りました。

$ k top pod --containers
POD        NAME       CPU(cores)   MEMORY(bytes)   
logstash   logstash   32m          735Mi           
logstash   ubuntu     1m           0Mi             
vector     ubuntu     1m           0Mi             
vector     vector     1m           20Mi

マニフェスト

apiVersion: v1
kind: Pod
metadata:
  name: logstash
spec:
  containers:
    - name: ubuntu
      image: ubuntu:22.04
      command: [ "/bin/sh" ]
      args: [ "-c", "while true; do echo $(date) hello >> /var/log/stdout.log; sleep 2; done" ]
      volumeMounts:
        - name: logs
          mountPath: /var/log
    - name: logstash
      image: docker.io/library/logstash:8.12.2
      env:
        - name: AWS_REGION
          value: us-west-2
        - name: AWS_ACCESS_KEY_ID
          value: dummy
        - name: AWS_SECRET_ACCESS_KEY
          value: dummy
      volumeMounts:
        - name: config-volume
          mountPath: /usr/share/logstash/config
        - name: logstash-pipeline-volume
          mountPath: /usr/share/logstash/pipeline
        - name: logs
          mountPath: /var/log
  volumes:
    - name: config-volume
      configMap:
        name: logstash-config
        items:
          - key: logstash.yml
            path: logstash.yml
    - name: logstash-pipeline-volume
      configMap:
        name: logstash-config
        items:
          - key: logstash.conf
            path: logstash.conf
    - name: logs
      emptyDir: {}
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: logstash-config
data:
  logstash.yml: |
    http.host: "0.0.0.0"
    path.config: /usr/share/logstash/pipeline
  logstash.conf: |
    input {
      file {
        path => "/var/log/stdout.log"
        mode => "tail"
      }
    }
    output {
      s3 {
        bucket => "stdout.log.test.trocco.io"
        endpoint => "http://10.0.1.20:4566"
      }
    }

Fluentd

S3 プラグインの利用に Gem の追加が必要だったり、K8s 上のログコレクターといえば fluentbit となっている流れに反するため見送りました。

Vector

ログの転送を滞りなく検証できたうえ、メモリリソースなどの効率も良かったため採用に至りました。
後発のツールのため情報が少ない点がデメリットではありますが、今回やりたいことはログの加工などもなくシンプルため、そこまで懸念することでもないと判断しました。

マニフェスト

apiVersion: v1
kind: Pod
metadata:
  name: vector
spec:
  containers:
    - name: ubuntu
      image: ubuntu:22.04
      command: [ "/bin/sh" ]
      args: [ "-c", "while true; do echo $(date) hello >> /var/log/stdout.log; sleep 2; done" ]
      volumeMounts:
        - name: logs
          mountPath: /var/log
    - name: vector
      image: "timberio/vector:0.37.0-distroless-libc"
      args:
        - --config-dir
        - /etc/vector/
      env:
        - name: AWS_REGION
          value: us-west-2
        - name: AWS_ACCESS_KEY_ID
          value: dummy
        - name: AWS_SECRET_ACCESS_KEY
          value: dummy
        - name: VECTOR_LOG
          value: "info"
        - name: VECTOR_SELF_NODE_NAME
          valueFrom:
            fieldRef:
              fieldPath: spec.nodeName
        - name: VECTOR_SELF_POD_NAME
          valueFrom:
            fieldRef:
              fieldPath: metadata.name
        - name: VECTOR_SELF_POD_NAMESPACE
          valueFrom:
            fieldRef:
              fieldPath: metadata.namespace
        - name: PROCFS_ROOT
          value: "/host/proc"
        - name: SYSFS_ROOT
          value: "/host/sys"
      ports:
        - name: prom-exporter
          containerPort: 9090
          protocol: TCP
      volumeMounts:
        - name: data
          mountPath: "/vector-data-dir"
        - name: config
          mountPath: "/etc/vector/"
          readOnly: true
        - name: logs
          mountPath: /var/log
  volumes:
    - name: config
      configMap:
        name: vector
    - name: data
      emptyDir: {}
    - name: logs
      emptyDir: {}
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: vector
data:
  agent.yaml: |
    data_dir: /vector-data-dir
    api:
      enabled: true
      address: 127.0.0.1:8686
      playground: false
    sources:
      file:
        type: "file"
        include: [ "/var/log/stdout.log" ]
    sinks:
      s3_archives:
        inputs: ["file"]
        type: "aws_s3"
        region: "us-east-1"
        bucket: "stdout.log.test.trocco.io"
        endpoint: "http://10.0.1.20:4566"
        batch:
          timeout_secs: 5
        compression: "none"
        key_prefix: "${CREATED_AT}/${JOB_TYPE}/${JOB_ID}/"
        filename_time_format: "%H-%M-%S%.3f"
        filename_append_uuid: false
        encoding:
          codec: "text"

サイドカーの問題点

ジョブの処理をしているメインコンテナである Rails コンテナのプロセス終了と同時に Vector も終了して欲しいところでした...
上記の希望が叶うのは K8s v1.28 から Alpha 版で提供された Native sidecar containers を利用した場合となっています。
ログ分離開始の時点では利用できなかったため、メインコンテナの終了した Pod で意味もなく動作し続ける Vector を停止する処理を自分で用意する必要がありました。

CronJob で定期削除

シンプルに Vector を停止する処理を実行するコンテナを CronJob で定期実行しています。

削除判定

メインコンテナの終了など、削除判定を厳格に行わないと、ログが転送されずに欠損してしまう不具合に繋がってしまいます。
CronJob の中身はシンプルにしたかったため、kubectl で削除判定を行うように試行錯誤しました。

kubectl get pods \
--selector "app.kubernetes.io/part-of=worker,mshr.dec/use-sidecar=true" \
--field-selector status.phase==Running \
-o=jsonpath="{range .items[?(@.status.containerStatuses[0].state.terminated.finishedAt <= '"$(date -d '60 second ago' '+%Y-%m-%dT%H:%M:%SZ')"')]}\
{.metadata.labels.batch\.kubernetes\.io/job-name}{'\t'}\
{.status.containerStatuses[0].state.terminated.reason}{'\t'}\
{.status.containerStatuses[1].ready}{'\n'}\
{end}" \
| awk '{if($2 == "Completed" && $3 == "true") print $1}' \
| xargs -r kubectl delete job

ラベルを利用して Pod を絞り込み、その後削除して良いか判定するためのステータスを抽出しています。
条件は以下の通りです。
Pod のステータス (status.phase) とコンテナのステータス (status.containerStatuses) をうまいこと抽出することで判定が可能となることが分かりました。
少し複雑になってはいますが、Native sidecar containers を利用可能となるまでの繋ぎなので許容しました。

	target	status.phase	status. containerStatuses["ruby"]. .state. terminated. reason	status. containerStatuses["vector"] .ready
Rails success Vector running	yes	Running	Completed	true
Rails success Vector not running	no	Pending	None	false
Rails running Vector running	no	Running	None	true
Rails running Vector not running	no	Running	None	false
Rails error Vector running	no	Running	Error	true

まとめ

K8s + Vector + S3 の組み合わせで、膨大なログデータを DB から剥がすことができました。
この中では複雑になってしまった CronJob についても EKS のバージョンアップで不要となるため、シンプルな構成でログの分離を実現することができたと思います。(作業は大変でしたが...)

話した内容は TROCCO のリアーキテクチャではあるものの、DB に大きいデータを保存してしまっているケースがある場合には、今回の内容を参考にしていただけると幸いです。
是非ともこういったアンチパターンによるエンジニアの疲弊は減らしていきましょう。

We are hiring

TROCCO を開発する primeNumber では、一緒に信頼性向上を実現してくれる SRE を絶賛募集中です！
まずはカジュアル面談でお会いしましょう 🙏
信頼性向上が選ばれる理由になる、裁量の大きいSRE【データ分析基盤総合支援SaaS TROCCO®/地方フルリモート有】