【第2回】
GlusterFSのログ収集にFluentdを使う

【技業LOG】技術者が紹介するNTTPCのテクノロジー

2013.11.06
分散ストレージ
高橋 敬祐

ソフトウェアエンジニア(分散ファイルシステム) チーフ・イノベイター
高橋 敬祐

取得資格:Ruby Association / Certified Ruby / Programmer Silver

技業LOG

GlusterFSは、内部でログ出力用の関数 gf_log をマクロで定義しており、Statedumpを除く全てのログ出力はこの関数を呼び出すことで行われます。

GlusterFSのログ

GlusterFSは、内部でログ出力用の関数 gf_log をマクロで定義しており、Statedumpを除く全てのログ出力はこの関数を呼び出すことで行われます。

libglusterfs/src/logging.h

#define gf_log_eh(fmt...) do {                   \
        FMT_WARN (fmt);                          \
        _gf_log_eh (__FUNCTION__, ##fmt);        \
    } while (0)

GlusterFSのログレベル

GlusterFSが定義するログのレベルは10あり、syslogよりもやや細かくなっています。

libglusterfs/src/logging.h

typedef enum {
    GF_LOG_NONE,
    GF_LOG_EMERG,
    GF_LOG_ALERT,
    GF_LOG_CRITICAL,  /* fatal errors */
    GF_LOG_ERROR,     /* major failures (not necessarily fatal) */
    GF_LOG_WARNING,   /* info about normal operation */
    GF_LOG_NOTICE,
    GF_LOG_INFO,      /* Normal information */
    GF_LOG_DEBUG,     /* internal errors */
    GF_LOG_TRACE,     /* full trace of operation */
} gf_loglevel_t;

ただし、実際に出力されるレベルはTRACE, DEBUG, INFO, WARNING, ERROR, CRITICAL, ALERTの7種類です。一般的に、運用上はERRORレベル以上で何らかのアクションを検討する必要がありますが、そのような上位レベルのログは全体の46%です。WARNINGとINFOが全体の26%、DEBUGとTRACEが全体の28%です。

GlusterFSのデフォルトのログレベルはINFOに設定されています。運用開始後はWARNING又はERRORレベル以上を出力することをお勧めします。ログレベルの設定は、対象のボリュームを作成した後であればいつでも、glusterコマンドから変更することができます。

各brickで出力するログレベルの変更

# gluster volume set <VOLUME_NAME> diagnostics.brick-log-level <TRACE|DEBUG|INFO|WARNING|ERROR|CRITICAL|ALERT|NONE>

Gluster Native Clientで出力するログレベルの変更

# gluster volume set <VOLUME_NAME> diagnostics.client-log-level <TRACE|DEBUG|INFO|WARNING|ERROR|CRITICAL|ALERT|NONE>

TRACEで出力する場合、データのI/O中は1行あたり約1ミリ秒の速度でログが出力されます。I/Oのテストを少し走らせるだけでもログファイルが数ギガバイトに膨れ上がるため、注意して使用してください。

GlusterFSのログローテーション

GlusterFS 3.4からは、デフォルトのインストールでログのローテーションが設定されます。

/etc/logrotate.d/glusterfs

# perform the log rotate every week
weekly
# keep the backup of 52 weeks
rotate 52
missingok
# compress the logs, but from the .2 onwards
compress
delaycompress
notifempty
# Rotate client logs
/var/log/glusterfs/*.log {
  sharedscripts
  postrotate
  /usr/bin/killall -HUP glusterfs > /dev/null 2>&1 || true
  /usr/bin/killall -HUP glusterd > /dev/null 2>&1 || true
  endscript
# Rotate server logs
/var/log/glusterfs/bricks/*.log {
  sharedscripts
  postrotate
  /usr/bin/killall -HUP glusterfsd > /dev/null 2>&1 || true
  endscript
}

また、各brickのログについては従来の方法でローテートすることもできます。

# gluster volume log rotate <VOLUME_NAME>

実行すると、ログファイル名にUNIX timeを連結した形でローテートされたログが出力されます。なお、このコマンドではcli.log, nfs.log, glustershd.log, etc-glusterfs-glusterd.vol.logはローテートされないことに留意してください。

GlusterFSのログを集約する

一般的なソフトウェア同様、GlusterFSのログはそれぞれのノードのローカルディスクに書き出されるため、内容の確認や監視の設定は、各ノードごとに個別に行う必要があります。小規模のクラスタで検証する程度であればこれでも何とかなりますが、ログを集約した方が便利で効率的であることは、言うまでも無いでしょう。
ログを集約する従来的な手段としては、syslogd、機能性を向上させたsyslog-ng、さらに信頼性を向上させたrsyslogなどがあります。実際GlusterFSのログ集約をこれらで実現することもできますが、これらとは異なる新しいツールがあります。

今回紹介するツールは、Fluentdです。FluentdはRubyとCで書かれたオープンソースのログコレクタで、ログをJSONに構造化して取り扱う点と、非常にプラガブルである点が特長です。ログを集約するだけでなく、検索や解析といった次のアクションに繋げることをコンセプトとしている点が、syslog系と大きく異なります。

今回は、Fluentdを使ってGlusterFSのログを集約してみましょう。

システム構成

今回のシステム構成は以下の通りです。ログサーバーとして"log-server"を、GlusterFSノードとして"glusterfs-stable-01", "glusterfs-stable-02"が存在します。ドメインはlocaldomainです。

+--------------------------+
| "glusterfs-stable-01"    |
|      CentOS 6.4 x86_64   |
|  +-- GlusterFS 3.4.0     |
|  |   Fluentd --+         |
+- | ----------- | --------+
   |             |   +---------------------+
   |             +-->| "log-server"        |
replica 2            |   CentOS 6.4 x86_64 |
   |             +-->|   Fluentd           |
   |             |   +---------------------+
+- | ----------- | --------+
|  |   Fluentd --+         |
|  +-- GlusterFS 3.4.0     |
|      CentOS 6.4 x86_64   |
| "glusterfs-stable-01"    |
+--------------------------+

Fluentdのインストール

Fluentdをインストールする前に、カーネルのパラメタをチューニングします。各ファイルに設定が無い場合、エディタで追記して下さい。

/etc/security/limits.conf

root soft nofile 65536
root soft nofile 65536
* soft nofile 65536
* hard nofile 65536

/etc/sysctl.conf

net.ipv4.tcp_tw_recycle = 1
net.ipv4.tcp_tw_reuse = 1
net.ipv4.ip_local_port_range = 10240 65535

ここで、ノードを再起動してパラメタの変更を反映させます。

# /sbin/shutdown -r now

続いてツールのインストールに入ります。Red Hat StorageやRed Hat Enterprise Linux、その他Red Hat系のOSを使う場合は、以下のコマンドでtd-agentをインストールします。td-agentはFluentdの商用版パッケージのような位置づけのソフトウェアです。

curl -L http://toolbelt.treasure-data.com/sh/install-redhat.sh | sh

なお、Debian系Linuxでのインストール方法については、公式サイトを参照してください。

プラグインのインストール

Inputプラグイン・Outputプラグインそれぞれに豊富なコミュニティ製プラグインを選択して、かつそれらを柔軟に組み合わせることができます。
今回は、fluent-plugin-glusterfsを使います。早速インストールしましょう。

export PATH=$PATH:/usr/lib64/fluent/ruby/bin
fluent-gem install fluent-plugin-glusterfs

Fluentdのコンフィギュレーション

今回は、GlusterFSクラスタの監視とオペレーションを行うglusterdデーモンが出力するログをログサーバーに集約する設定を行います。

ログサーバー側のコンフィギュレーション

<source>
  type forward
  port 24224
  bind 0.0.0.0
</source>
<match glusterfs_log.glusterd>
  type file
  path /var/log/td-agent/glusterd
</match>

GlusterFSノード側のコンフィギュレーション

<source>
  type glusterfs_log
  path /var/log/glusterfs/etc-glusterfs-glusterd.vol.log
  pos_file /var/log/td-agent/etc-glusterfs-glusterd.vol.log.pos
  tag glusterfs_log.glusterd
  format /^(?<message>.*)$/
  refresh_interval 1800
</source>
<match glusterfs_log.**>
  type forward
  send_timeout 60s
  recover_wait 10s
  heartbeat_interval 1s
  phi_threshold 8
  hard_timeout 60s
  <server>
    name log-server
    host 192.168.1.10
    port 24224
    weight 60
  </server>
  <secondary>
    type file
    path /var/log/td-agent/forward-failed
  </secondary>
</match>

Fluentdの起動

一般的なinit.dスクリプトと同様の方法で、Fluentdを起動します。

# /etc/init.d/td-agent
Usage: td-agent {start|stop|reload|restart|condrestart|status}
# /etc/init.d/td-agent start
Starting td-agent:                        [  OK  ]
# /etc/init.d/td-agent status
td-agent (pid  1732) is running...

ログ出力のテスト

実際にGlusterFSのログを出力させて、Fluentdの動作を確認してみましょう。起動中のvolumeを停止することでエラーログを出力させます。

こちらが現在起動中のvolumeの情報です。

# gluster volume info rep2
Volume Name: rep2
Type: Replicate
Volume ID: 3b211a1d-3942-4b28-9d4a-02d1f101ba26
Status: Started
Number of Bricks: 1 x 2 = 2
Transport-type: tcp
Bricks:
Brick1: glusterfs-stable-01:/mnt/lv0/rep2
Brick2: glusterfs-stable-02:/mnt/lv0/rep2
Options Reconfigured:
diagnostics.client-log-level: ERROR
diagnostics.brick-log-level: ERROR

glusterコマンドでvolumeを停止します。

# gluster volume stop rep2
Stopping volume will make its data inaccessible. Do you want to continue? (y/n) y
volume stop: rep2: success

以下のエラーログが出力されました。

[root@glusterfs-stable-01 ?]# grep " E " /var/log/glusterfs/etc-glusterfs-glusterd.vol.log [2013-08-13 06:25:09.787080] E [glusterd-utils.c:1111:glusterd_service_stop] 0-management: Unable to open pidfile: /var/lib/glusterd/vols/rep2/run/glusterfs-stable-01-mnt-lv0-rep2.pid
[2013-08-13 06:25:09.788629] E [glusterd-utils.c:1493:glusterd_brick_unlink_socket_file] 0-management: Failed to remove /var/run/28a960d55e71fa6508f91af9c513c647.socket error: No such file or directory
[2013-08-13 06:25:10.806701] E [glusterd-utils.c:3627:glusterd_nodesvc_unlink_socket_file] 0-management: Failed to remove /var/run/0c4e1b43276a4d68f495aa958ce8a813.socket error: Resource temporarily unavailable
[2013-08-13 06:25:11.810870] E [glusterd-utils.c:3627:glusterd_nodesvc_unlink_socket_file] 0-management: Failed to remove /var/run/2a81a50174ee99b1af599e491bcff580.socket error: No such file or directory
[root@glusterfs-stable-02 ?]# grep " E " /var/log/glusterfs/etc-glusterfs-glusterd.vol.log [2013-08-13 06:25:09.792969] E [glusterd-utils.c:1111:glusterd_service_stop] 0-management: Unable to open pidfile: /var/lib/glusterd/vols/rep2/run/glusterfs-stable-02-mnt-lv0-rep2.pid
[2013-08-13 06:25:09.793698] E [glusterd-utils.c:1493:glusterd_brick_unlink_socket_file] 0-management: Failed to remove /var/run/2f21f26d9b4689f47f0294052aaffa16.socket error: No such file or directory
[2013-08-13 06:25:10.810787] E [glusterd-utils.c:3627:glusterd_nodesvc_unlink_socket_file] 0-management: Failed to remove /var/run/15425534056cb066c758bdac00a54f5a.socket error: Resource temporarily unavailable
[2013-08-13 06:25:11.815450] E [glusterd-utils.c:3627:glusterd_nodesvc_unlink_socket_file] 0-management: Failed to remove /var/run/cbdcaa71bf7e60d30127c6bf065b6436.socket error: No such file or directory

ログサーバーには以下のログが出力されています。

% grep "\"log_level\":\"E\"" glusterd.20130813.b4e3ce2540843e594
2013-08-13T06:25:09+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:09","time_usec":"792969","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"1111","function_name":"glusterd_service_stop","component_name":"0-management","message":"Unable to open pidfile: /var/lib/glusterd/vols/rep2/run/glusterfs-stable-02-mnt-lv0-rep2.pid","hostname":"glusterfs-stable-02.localdomain"}
2013-08-13T06:25:09+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:09","time_usec":"793698","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"1493","function_name":"glusterd_brick_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/2f21f26d9b4689f47f0294052aaffa16.socket error: No such file or directory","hostname":"glusterfs-stable-02.localdomain"}
2013-08-13T06:25:10+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:10","time_usec":"810787","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"3627","function_name":"glusterd_nodesvc_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/15425534056cb066c758bdac00a54f5a.socket error: Resource temporarily unavailable","hostname":"glusterfs-stable-02.localdomain"}
2013-08-13T06:25:11+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:11","time_usec":"815450","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"3627","function_name":"glusterd_nodesvc_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/cbdcaa71bf7e60d30127c6bf065b6436.socket error: No such file or directory","hostname":"glusterfs-stable-02.localdomain"}
2013-08-13T06:25:09+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:09","time_usec":"787080","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"1111","function_name":"glusterd_service_stop","component_name":"0-management","message":"Unable to open pidfile: /var/lib/glusterd/vols/rep2/run/glusterfs-stable-01-mnt-lv0-rep2.pid","hostname":"glusterfs-stable-01.localdomain"}
2013-08-13T06:25:09+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:09","time_usec":"788629","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"1493","function_name":"glusterd_brick_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/28a960d55e71fa6508f91af9c513c647.socket error: No such file or directory","hostname":"glusterfs-stable-01.localdomain"
2013-08-13T06:25:10+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:10","time_usec":"806701","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"3627","function_name":"glusterd_nodesvc_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/0c4e1b43276a4d68f495aa958ce8a813.socket error: Resource temporarily unavailable","hostname":"glusterfs-stable-01.localdomain"}
2013-08-13T06:25:11+09:00 glusterfs_log.glusterd {"date":"2013-08-13","time":"06:25:11","time_usec":"810870","log_level":"E","source_file_name":"glusterd-utils.c","source_line":"3627","function_name":"glusterd_nodesvc_unlink_socket_file","component_name":"0-management","message":"Failed to remove /var/run/2a81a50174ee99b1af599e491bcff580.socket error: No such file or directory","hostname":"glusterfs-stable-01.localdomain"}

各ノードで出力されたログがJSON形式へと構造化され、ログサーバーへ集約されたことが、確認できました。なお、出力されたログは、日時・タグ・JSONの形式となります。

fluent-plugin-glusterfsの場合、デフォルトでは以下のJSON形式となっています。

{   "date":"2013-08-13",
  "time":"06:25:11",
  "time_usec":"810870",
  "log_level":"E",
  "source_file_name":"glusterd-utils.c",
  "source_line":"3627",
  "function_name":"glusterd_nodesvc_unlink_socket_file",
  "component_name":"0-management",
  "message":"Failed to remove /var/run/2a81a50174ee99b1af599e491bcff580.socket error: No such file or directory",
  "hostname":"glusterfs-stable-01.localdomain"
}

fluent-plugin-glusterfsのソースコードは、以下のパス名でインストールされています。

/usr/lib64/fluent/ruby/lib/ruby/gems/1.9.1/gems/fluent-plugin-glusterfs-1.0.0/lib/fluent/plugin/in_glusterfs_log.rb

今回はデフォルトの設定で、全てのログを集約しましたが、このコードを書き換えることで、集約するログレベルの変更、要素名の変更、集約する要素の限定などのカスタマイズを行うことができます。

集約したログの活用

ログはただ集めただけでは意味がありません。いかに活用するかが、システムの監視運用そしてサービスの競争力向上にとっての重要なキーとなります。今回は集約したログをテキストのログファイルに書き出しましたが、Fluentdのプラグインを利用することで、リレーショナル・データベース、NoSQLデータベース、オブジェクト・ストレージ、メール、IRC、その他様々なデータストアやデータストリームへと書き出すことができます。また、途中でフィルターとなるプラグインを挟むことでログデータのクレンジングを行ったり、muninやdstatなどの情報も同時に集約することで監視機能を強化したりと、簡単な工夫でGlusterFSクラスタのログデータ解析や監視を高度化することができます。

まとめ

今回は、前半でGlusterFSのログの詳解を、後半でGlusterFSクラスタに散在するログを集約するツールとしてFluentdを使用する方法をご紹介しました。Fluentdを利用することで、単にログの集約だけでなく、監視の強化、ひいてはログ解析からのクラスタ運用自動化の実現が期待されます。また、本稿執筆時点でFluentdには150以上のプラグインがあるため、通常の運用監視では思いつかないような効率化が実現できる可能性がありますし、検証のやり方も変わってくると思われます。Fluentdについても、GlusterFSに限らず様々なソフトウェアのログに対して利用可能ですので、ぜひ試してみてください。

GlusterFSは機能毎にモジュール構造になっており、分散以外にもレプリケーションやストライピングなどのクラスタ機能を持っています。また、オブジェクトストレージのインタフェースも追加されました。今回紹介できなかったこれらの機能に関しては、別の機会に解説できればと思います。

参考文献

  • Fluentdインストールの前に
    https://docs.fluentd.org/v1.0/articles/before-install
  • Managing GlusterFS Volumes - Tuning Volume Options
    https://access.redhat.com/documentation/en-US/Red_Hat_Storage/2.0/html/Administration_Guide/chap-User_Guide-Managing_Volumes.html
  • Installing Fluentd Using rpm Package
    http://docs.fluentd.org/articles/install-by-rpm

おすすめ記事

    お気軽にご相談ください