fluentdでdockerコンテナのログをファイルごとに出し分けてみたお話

fluentdとは

fluentdとはログ収集ツールです。
様々な形式のinputからログを収集でき、それを必要に応じて整形・加工してログ出力できます。

環境

• OS：debian 10.3
• docker：19.03.11
• docker-compose：1.16.1
• fluentd:1.3.2

今回の目標

今回の目標はサーバーのログを標準出力からファイル出力へ切り替えることです。
さらに、ファイル出力も全てのログを出力するログファイルと、エラーログのみを出力するエラーログファイルの2種類作成していきます。

fluentdの設定ファイルについて

デフォルトでは、 /fluentd/etc/fluent.conf が読み込まれます。

tag

fluentdではログをtagというもので管理していきます。
このtagを使って設定を任意のログのみに適用できたりします。

ディレクティブ

fluentdの設定はディレクティブと呼ばれるもので設定していきます。
ディレクティブには下記のようなものがあります。

• source: ログの入力を設定するディレクティブ。
• match: ログの出力を設定するディレクティブ。引数にtagを指定。
• filter: ログに対して行う処理を設定するディレクティブ。引数にtagを指定。
• label: @label でラベル名を設定することで、<label ラベル名> の設定にルーティングできる。

下記はmatchディレクティブの例です。

<match myapp.access>
  @type file
  path /var/log/fluent/access
</match>

myapp.access の部分がtagになります。
@type の部分が次に説明する、プラグインを指定しています。

設定ファイルの主なディレクティブの流れとしては、
< source >　→　< filter > や < label >など　→　......　→　< match >
となることを頭に入れておくと設定ファイルの読み書きがしやすくなると思います。
参考：ディレクティブ 公式ドキュメント

プラグイン

fluentdには標準のプラグインが豊富にあります。
プラグインは先ほどのディレクティブ内に @type で指定することで利用できます。
このプラグインを使うことで様々な形式でログを入出力できたり、ログを加工したりできるようになります。

下記は filterディレクティブ のプラグインの一部です。

• record_transformer:ログにフィールドを追加したり削除したりできる。
• grep:正規表現でマッチするログだけを通したり、マッチするログを出力しないようにしたりできる。
• parser:ログ内のフィールドをjsonなどの形式を指定してパースすることができる。

参考：filterプラグイン 公式ドキュメント

今回使う各ファイル

ファイル階層

├── app
│   └── main.go
├── docker
│   ├── app
│   │   ├── app
│   │   └── Dockerfile
│   ├── docker-compose.yml
│   └── fluentd
│       ├── config
│       │   └── fluent.conf
│       ├── Dockerfile
│       └── log
│           ├── alert.buf
│           └── log.buf
└── Makefile

app/main.go

今回はこちらの超簡易サーバーを使っていきたいと思います。

main.go

package main

import (
    "fmt"
    "net/http"

    "github.com/sirupsen/logrus"
)

func main() {
    // server起動
    http.HandleFunc("/sample", outputQueryString)
    http.ListenAndServe(":8080", nil)
}

func outputQueryString(w http.ResponseWriter, r *http.Request) {
    log := logrus.New()
    // 処理開始のログ
    log.Infoln("Start!")

    // クエリストリングからキーが name の値を取得
    qs := r.URL.Query().Get("name")
    // キーが name の値がない場合のエラー処理
    if qs == "" {
        log.Errorln("Query string is nothing.")
        w.WriteHeader(http.StatusBadRequest)
        return
    }

    // name があった場合の出力
    fmt.Fprintf(w, "Your name is %s", qs)
    log.Infoln("Complete!")
}

このサーバーのログをfluentdで収集します。
こちらのサーバーは、

1. (IPアドレス):8080/sample?name=XXX にアクセスすると、「Your name is XXX」を返す
2. (IPアドレス):8080/sample?key=XXX のようにクエリストリングのキーに name の値がない場合、エラーログを出力し、400エラーを返す

という処理内容になってます。

出力されるログは、

1. アクセスされたときに処理開始のログ Start! を出力
2. key が name のクエリストリングがなかった場合、エラーログ Query string is nothing. を出力
3. 処理が正常終了した場合、処理完了のログ Complete! を出力

となっています。
なので、ログファイルには1, 2, 3のログが、エラーログファイルには2のログのみが出力されることになります。

docker/app/app

app/main.go の実行ファイル。
こちらをappのコンテナ内にコピーして実行します。

docker/app/Dockerfile

Dockerfile

FROM alpine:latest

COPY app /bin

CMD "app"

今回、appのdockerイメージはalpineを使用しています。
alpineを選択した理由はdockerイメージの容量が小さくなるからです。
詳しくはこちらの記事を参考にしてみてください。
Alpine Linux で Docker イメージを劇的に小さくする

Dockerfileの内容としては、先ほどのappの実行ファイルをコンテナ内の /bin ディレクトリにコピーして実行しているだけです。

docker/fluentd/config/fluent.conf (fluentd設定ファイル)

いよいよ、本命のfluentdの設定ファイルです。
ちょっと長いかもしれませんが、ブラウザバックするのは待ってください。
わかります。わたしも設定ファイルアレルギーの重症者ですから。
ですが、安心してください。
部分に分けて説明をしているので、どうか我慢して少し読み進めてみてください。
わからないところがあればコメントいただければできるだけ(アレルギー重症者レベルで)回答します。

fluent.conf

<source>
  @type  forward
  @label @mainstream
  port  24224
</source>

<label @mainstream>
  <match docker.**>
    @type copy
    <store>
      @type relabel
      @label @all_log
    </store>
    <store>
      @type relabel
      @label @err_log
    </store>
  </match>
</label>

<label @all_log>
  <match **>
    @type file
    path /var/log/fluent/log_*.log
    format ltsv
    buffer_type file
    buffer_path /var/log/fluent/log.buf
    symlink_path /var/log/fluent/log_current
    time_slice_format %Y%m%d
    flush_at_shutdown true
    append true
  </match>
</label>

<label @err_log>
  <filter **>
    @type grep
    <regexp>
      key log
      pattern /level=(warn|error)/
    </regexp>
  </filter>

  <match **>
    @type file
    path /var/log/fluent/alert_*.log
    format ltsv
    buffer_type file
    buffer_path /var/log/fluent/alert.buf
    symlink_path /var/log/fluent/alert_current
    time_slice_format %Y%m%d
    flush_at_shutdown true
    append true
  </match>
</label>

設定ファイルの内容説明

設定ファイルの内容を上から分けて見ていきます。

<source>
  @type  forward
  @label @mainstream
  port  24224
</source>

この sourceディレクティブでは、inputの設定を定義しています。
取得したログに対して @mainstream というラベルを設定しているので、この次は <label @mainstream> の設定に飛びます。

<label @mainstream>
  <match docker.**>
    @type copy
    <store>
      @type relabel
      @label @all_log
    </store>
    <store>
      @type relabel
      @label @err_log
    </store>
  </match>
</label>

この <label @mainstream> では、ログの複製を行っています。
@type copy でログの複製ができます。
なぜ複製しているのかというと、この後ログを、全てのログが出力されるログファイルと、エラーログだけが出力されるエラーログファイルに分けたいからです。
複製したログには @all_log 、 @err_log というラベルを再設定しているので、
それぞれ <label @all_log> 、 <label @err_log> のディレクティブに飛びます。

<label @all_log>
  <match **>
    @type file
    path /var/log/fluent/log_*.log
    format ltsv
    buffer_type file
    buffer_path /var/log/fluent/log.buf
    symlink_path /var/log/fluent/log_current
    time_slice_format %Y%m%d
    flush_at_shutdown true
    append true
  </match>
</label>

この <label @all_log> では、ログファイルの出力設定を行っています。

• path ではファイルの出力先を指定しています。* は後述の time_slice_format で指定したフォーマットで日付や日時が入ります。
• buffer_type ではファイルに出力する前のバッファリングをfileに出力するか、メモリに溜めておくかを設定できます。メモリの方が処理は速いですが、fluentdが途中で落ちるとログが消失する可能性があります。
• buffer_path ではバッファをfile出力にした際の出力先を指定しています。
• symlink_path ではファイル出力しているバッファへのシンボリックリンクを設定しています。これにより、バッファが出力されているファイル名がどんなものであれ、同じファイル名でアクセスできるようになります。
• time_slice_format ここで設定したフォーマットでファイル名の * が置き換えられます。デフォルトでは %Y%m%d なので日付単位でファイルが生成されますが、ここの設定を時間単位にすればファイルが1時間ごとに生成されるようになるので、ファイルの生成単位を設定しているとも言えます。
• flush_at_shutdown では、fluentdがシャットダウンされた際に最後に1度だけバッファの内容を出力するかどうかを設定しています。trueなら出力を試します。
• append では、既にファイル出力先ファイルがある場合、追記するか別ファイルに出力するかを設定しています。trueなら追記します。

<label @err_log>
  <filter **>
    @type grep
    <regexp>
      key log
      pattern /level=(warn|error)/
    </regexp>
  </filter>

  <match **>
    @type file
    path /var/log/fluent/alert_*.log
    format ltsv
    buffer_type file
    buffer_path /var/log/fluent/alert.buf
    symlink_path /var/log/fluent/alert_current
    time_slice_format %Y%m%d
    flush_at_shutdown true
    append true
  </match>
</label>

この <label @err_log> では、エラーログファイルの出力設定を行っています。
filterディレクティブでは、grepプラグインを使い、ログのフィルタリングを行っています。
grepプラグインでは、フィールドのキーを設定して、それに対して正規表現で通すログ通さないログを設定できます。
この設定では、 log というキーに対して level=warn か level=error という値を持つログのみを通します。
matchディレクティブについては、上記ログファイル出力設定と重複するので割愛します。

以上が、fluent.confの設定内容です。
labelのおかげで流れを掴みやすく、他の設定ファイルより読みやすいのではと思います。

fluentdのDockerfile

Dockerfile

FROM fluent/fluentd:latest

dockerイメージで、fluentdを指定しているだけです。

アプリのcompose.yml

docker-compose.yml

version: "3.3"

services:
  app:
    build: ./app
    container_name: app
    restart: always
    ports:
      - "8080:8080"
    logging:
      driver: "fluentd"
      options:
        fluentd-address: "localhost:24224"
        tag: "docker.{{.Name}}"
    depends_on:
      - fluentd

  fluentd:
    build: ./fluentd
    container_name: fluentd
    volumes:
      - ./fluentd/config:/fluentd/etc
      - ./fluentd/log:/var/log/fluent
    restart: always
    ports:
      - "24224:24224"

appの logging というところでログ出力先の設定を行っています。
こちらのように driver に fluentd を指定することで、fluentdでログを収集できるようになります。
optionsではfluentdのコンテナへの接続とログのtagの設定をしています。

fluentdのvolumesでは、2つのディレクトリをマウントしています。
1つめの ./fluentd/config では、デフォルトのfluent.confが格納してあるディレクトリをマウントすることで、設定ファイルを上書きしています。
2つめの ./fluentd/log では、fluentdのログファイルが出力されている /var/log/fluent をマウントすることで、ログファイルをローカルの /docker/fluentd/log のディレクトリから取得できるようにしています。

実際に起動してみる

それでは、実際に起動してみます。

$cd docker/; docker-compose up -d --build
Creating network "docker_default" with the default driver
Building fluentd
Step 1/1 : FROM fluent/fluentd:latest
 ---> 9406ff63f205

Successfully built 9406ff63f205
Successfully tagged docker_fluentd:latest
Building app
Step 1/3 : FROM alpine:latest
 ---> a24bb4013296
Step 2/3 : COPY app /bin
 ---> a57975cbc6b8
Step 3/3 : CMD "app"
 ---> Running in fa1f4446976e
Removing intermediate container fa1f4446976e
 ---> 515558e9745f

Successfully built 515558e9745f
Successfully tagged docker_app:latest
Creating fluentd ...
Creating fluentd ... done
Creating app ...
Creating app ... done

$ docker ps
CONTAINER ID        IMAGE               COMMAND                  CREATED             STATUS              PORTS                                NAMES
b76f4a1c2bdd        docker_app          "/bin/sh -c \"app\""     57 seconds ago      Up 56 seconds       0.0.0.0:8080->8080/tcp               app
b732ea83c8e7        docker_fluentd      "/bin/entrypoint.sh …"   58 seconds ago      Up 57 seconds       5140/tcp, 0.0.0.0:24224->24224/tcp   fluentd

fluentdとサーバーのコンテナが起動できました。
では、アクセスしてみましょう。
まずは、 (IPアドレス):8080/sample?name=Qiita でアクセスしてみます。

クエリストリングで指定した Qiita がちゃんと表示されてますね。

続いて、 (IPアドレス):8080/sample?key=Qiita でアクセスしてみます。

こちらもちゃんとエラーが返されてます。サーバーは意図通り動いてそうですね。

続いて、ログについて見ていきます。
log_yyyymmdd.log には全てのログが出力されます。
alert_yyyymmdd.log にはエラーログのみが出力されます。
実施日が2020/06/29なので yyyymmdd は 20200629 になります。

log_20200629.log

source:stderr   log:time="2020-06-29T14:18:06Z" level=info msg="Start!" container_id:1b3e5a8deaaa2322bec250db7a47d67f49dd5654bc037af1730e31db1c4af74d   container_name:/app
container_id:1b3e5a8deaaa2322bec250db7a47d67f49dd5654bc037af1730e31db1c4af74d   container_name:/app source:stderr   log:time="2020-06-29T14:18:06Z" level=info msg="Complete!"
source:stderr   log:time="2020-06-29T14:18:09Z" level=info msg="Start!" container_id:1b3e5a8deaaa2322bec250db7a47d67f49dd5654bc037af1730e31db1c4af74d   container_name:/app
container_id:1b3e5a8deaaa2322bec250db7a47d67f49dd5654bc037af1730e31db1c4af74d   container_name:/app source:stderr   log:time="2020-06-29T14:18:09Z" level=error msg="Query string is nothing."

alert_20200629.log

container_id:1b3e5a8deaaa2322bec250db7a47d67f49dd5654bc037af1730e31db1c4af74d   container_name:/app source:stderr   log:time="2020-06-29T14:18:09Z" level=error msg="Query string is nothing."

log_20200629.log を見てみるとの1行目と3行目には処理開始のログが出力され、2行目と4行目にはそれぞれ正常終了時のログとエラー時のログがすべて出力されていますね。
一方、alert_20200629.log の方には log_20200629.log の4行目と同じログ(エラーログ)が出力されています。
これでエラー時のログのみ見たい場合は alert_20200629.log を見ればよくなりましたね。

おわりに

今回はfluentdの設定ファイルの概要と実際に使ってみた実例を紹介しました。
ここまで読んでいただいた方には、fluentdの設定ファイルがそこまで難解ではないというのが少しは伝わったのではないでしょうか？
設定ファイルアレルギーの重症者であるわたしでも簡単な設定ファイルについては記述できるようになりました。
みなさんもぜひこの記事をきっかけにfluentdデビューをしてスマートなログ収集ライフを！