このサイトは、もともと作者の自分用メモとして書き始めたものです。書いてあることが全て正しいとは限りません。他の文献、オフィシャルなサイトも確認して、自己責任にて利用してください。

rsyslog

RHEL/CentOS 6に標準でインストールされる rsyslog は 5.8.x。しかし、rsyslog7 という名称で rsyslog 7.4.x のパッケージも用意されていて、5.8.x からアップグレードすることが可能だ。rsyslogのドキュメントでも言われているが、バージョン5 は機能が甚だ中途半端。処理速度も遅い。当ページでは、rsyslog 7.4.10 で Syslogサーバを仕立てる上で分かった rsyslog の機能やコツについて述べる。ちなみに RHEL/CentOS 7 では最初から rsyslog 7.4.x が標準となっている。

<- バージョン5 での検証と解説はこちら

RHEL/CentOS 6での rsyslog 5->7 へのアップグレード方法

RHEL/CentOS 6でも rsyslog 7.4 が rsyslog7 という名称で選択可能パッケージとして利用できるようになった。2014年10月、RHEL/CentOS 6.6 の時期からだ。このエラータ情報を見ると、Red Hat社は rsyslog7 へのアップグレードを推奨しているようだ。ただし、単に `yum update rsyslog7' とやっても依存関係(コンフリクト)のため入れ替えできない。yumシェルを使うとできる。

root# yum shell
> install rsyslog7
> remove rsyslog
> run
> exit
root# rpm -qa |grep rsyslog
rsyslog7-7.4.10-x.el6.x86_64
root# chkconfig --add rsyslog  <- 一旦スタートアップが解除されるので再登録が必要

バージョン7用の /etc/rsyslog.conf.rpmnew、/etc/sysconfig/rsyslog.rpmnew が新たに作られるので、バージョン5用の rsyslog.conf, sysconfig/rsyslog を退避させるなどして、正規のファイル名に置き換えてカスタマイズのベースにする。/etc/rsyslog.d/ 配下のファイルは置き換えや追加はされない。

リモートロギングのための設定

ここでは 514/UDP でのリモートログ受け入れを基本とし、TCPについては補足的に述べるに留める。TCPの方がログ欠落の可能性は低いが、ファイヤーウォールアプライアンスなど、未だにUDPでしかログを送れない機器が多く存在するからだ。

Syslogサーバ側の設定

これだけはやっておきたいシステム設定

同時オープンファイル上限数やエフェメラルポート範囲の拡大は基本中の基本。以下のファイルに下記の記述が含まれるように編集。

/etc/sysctl.conf

fs.file-max                   = 6815744
fs.aio-max-nr                 = 1048576
net.ipv4.ip_local_port_range  = 9000 65500

`sysctl -p` で反映。

/etc/security/limits.d/91-nofile.conf

root       soft    nofile    4096
root       hard    nofile    65536

/etc/security/limits.d/90-nproc.conf (RHEL/CentOS 6.x では元々こうなっているはず)

*          soft    nproc     1024
root       soft    nproc     unlimited

ulimit関係の設定変更は次回のrootシェルセッションから反映される。

主設定ファイル /etc/rsyslog.conf

バージョン7 では設定の書き方が大幅に変わった。バージョン5 までログ仕分けルールの条件文などごく一部で使われていた レイナースクリプト (RainerScript) が、コンフィグ全体のパーサーエンジンになったようだ。ただし、ディレクティブの頭が $ で始まるバージョン5 の書き方 (以降「レガシー」と呼ぶ) もそのほとんどが混在で使え、一部、レガシーなディレクティブしか用意されていない設定機能さえある。以下のコンフィグ例では、新記述法で置き換えられるものはなるべく新記述法で書くようにしている。RuleSet を意識した構造とインクルードコンフィグファイルを使うと、きれいで変更もしやすい設定ができる。

レガシー記述法と新記述法の混在には多少注意が必要だ。新記述法で定義したルールセットに対してはレガシー式でオプションを唱えても反映されなかったり、レガシー式で定義したテンプレートが CALL ステートメントで呼べないなどの落とし穴があるからだ。そういったことを避けるためにも、特に理由のない限り新記述法で貫き通した方がよい。

module(load="imuxsock")
module(load="imklog")
module(load="imudp")         <- UDPインプットモジュールのロード
#module(load="imptcp")       <- TCPをリスニングする場合はこちらをロード(TLS機能なし版)
#module(load="imtcp")
 
#### GLOBAL DIRECTIVES ####
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$IncludeConfig /etc/rsyslog.d/*.conf
 
#### RULES ####         <- ここは暗黙のデフォルトRuleSet "RSYSLOG_DefaultRuleset" のコンテキスト
#kern.*                                                 /dev/console
*.info;mail.none;authpriv.none;cron.none                /var/log/messages
# <-- 通常のローカルログフィルタ記述が続く。略 -->
 
# A template to for higher precision timestamps + severity logging
$template SpiceTmpl,"%TIMESTAMP%.%TIMESTAMP:::date-subseconds% %syslogtag% %syslogseverity-text%:%msg:::sp-if-no-1st-sp%%msg:::drop-last-lf%\n"
 
:programname, startswith, "spice-vdagent"	/var/log/spice-vdagent.log;SpiceTmpl
 
#### Remote server log RuleSet ###        <- ここからがUDPリモートロギングの設定
template(name="Centos6uPerProg" type="string" string="/rlog/centos6u/%programname%.log") <- バージョンによっては
                                              templateをruleset()内に書くと設定パースエラーになるようなのでここへ移した。
ruleset(name="RemoteUDP"                  <- UDPリモートロギング用RuleSetへのコンテキスト切り替え。まだ存在しないのでここで生成される
        queue.type="FixedArray"           <- パフォーマンスと信頼性向上のためルールセット専用のインプットキューを設ける
       ) {
    $IncludeConfig /etc/rsyslog.d/remote-udp.conf_r   <- フィルタはインクルードコンフィグファイルに書く。ローカルとは別の拡張子にするとよい
}
 
#### Remote server log RuleSet for TCP ###
#ruleset(name="RemoteTCP"                 <- TCPリモートロギングRuleSetのコンテキスト(使うなら)
#        queue.type="FixedArray"
#       ) {
#    $IncludeConfig /etc/rsyslog.d/remote-tcp.conf_r
#}
 
input(type="imudp" port="514" ruleset="RemoteUDP")    <- UDPのリッスンを有効化
#input(type="imudp" address="192.168.1.25" port="10514" ruleset="RemoteUDP") <- 追加で複数のUDPポートで待ち受けることも可能
#input(type="imptcp" address="192.168.1.25" port="514" ruleset="RemoteTCP")  <- TCPのリッスンを有効化(使うなら)

input ステートメントで address オプションを使うと、リッスンするネットワークインターフェイスを限定することもできる。普通は書かないので `address="*"' を指定したのと同じなわけだ。ただし、7.4 のドキュメントを見る限り、imtcp モジュールには address オプションが欠けている(v8のドキュメントには載っている)。

TCPで待ち受ける場合、通信をTLSで保護するつもりがないのなら、imtcpモジュールより、平文通信に機能を絞った imptcpモジュールを使った方が理屈的に言って処理速度が速いはずだ。自分で測定してみたわけではないが、GitHubに"Receiving massive amounts of messages with high performance"というガイドもある。その他のチューニングポイントは後述の CALLステートメントによるルールセットの階層化+チューニング を参照いただきたい。

UDPリモートログ用インクルードコンフィグ /etc/rsyslog.d/remote-udp.conf_r

IPアドレス 192.168.1.24 のリモートサーバから送信されてくるログのうち、ntpd のログを /rlog/centos6u/ntpd.log に、Syslogファシリティ AUTHPRIV のログを /rlog/centos6u/secure に記録する例。書き方はいろいろある(ありすぎて困る)が、

$AllowedSender UDP, 192.168.1.24/32
 
if $fromhost-ip == '192.168.1.24' then {
    if $programname startswith 'ntpd' then -?Centos6uPerProg
    if $syslogfacility-text == 'authpriv' then -/rlog/centos6u/secure
    stop
}

条件文は、波括弧 {} を使うとネストできる(※Note参照)。?テンプレート名 やファイル名の前の '-`は、従来の syslogd と同様、遅延書き込みを有効にすることを意味する。最後の行のアクションである stop は、バージョン5 の `~' (discard) に代わるもの。rsyslog のルールセットは、書かれている順番に、STOP ステートメントが現れるまで全フィルタが評価される。`&' は「直前の条件と同じ」の意味だ。それ以上どこにも記録しないログをしっかり STOP するように心掛ければ、上記ルール群の下に例えば他のサーバからのログを処理するフィルタ群があった場合でも、もうそこから後へは流れず、間違って他のログファイルへ流れ込んだり無用なリソースを処理に費やしたりせずに済む。

一番上の $AllowedSender は、ソースアドレスによる受け付け制限。誰かが勝手に Syslogサーバへログを送る設定をして、知らぬ間にCPUやディスクを食い潰されてはたまらない。'UDP' のところはもちろん、TCPインプットモジュールなら 'TCP' に置き換えていただきたい。エージェントアドレスは書き方の見本として /32 を付けたが、単一のIPアドレスなら /prefix は書く必要はない。名前解決のできる環境ならホスト名や *.hoge.cxm のようなワイルドカード指定もできる。複数指定したい時は、カンマ区切りで列挙するか、$AllowedSender ステートメントを複数回唱えてもよいとされている。ソース制限機能は将来なくなる予定と述べられているが、使えるものは使う。

2行目は rsyslog 独特のテンプレート という機能で、ファイル名やディレクトリ名をプロパティを使って動的に発生させる用途の他、ログフォーマットをカスタマイズしたり、データベースにログを格納する場合の insertクエリを定義したりでき、使い回しができる。テンプレートを使わずに書くと次のようになる。

$AllowedSender UDP, 192.168.1.24/32
 
if $fromhost-ip == '192.168.1.24' then {
    if $programname startswith 'ntpd' then -/rlog/centos6u/ntpd.log
    if $syslogfacility-text == 'authpriv' then -/rlog/centos6u/secure
    stop
}

実は、この例ではわざと`$programname == 'ntpd'' と書かずに startswith で評価しているので、前記のテンプレートパターンでは ntpdate のログが来ると ntpdate.log という別のファイルに書かれてしまう。意図によってはこのように固定ファイル名にした方がすっきりするだろう。ごちゃ混ぜにして `... then -/rlog/centos6u/%programname%.log' とは書けない - やってみると、そのものズバリの %programname%.log というログファイルが出来上がってしまった。

if $fromhost-ip == 'x.x.x.x' then {
  if $programname startswith 'ntpd' then /log/file
  if $syslogfacility-text == 'authpriv' then /log/otherfile
}
& stop

ruleset(name="RemoteUDP"
        queue.type="FixedArray"
       ) {
    stop
}

CALLステートメントによるルールセットの階層化 + チューニング

rsyslog 7 では、CALL ステートメントでルールセットを階層化することができる。iptables のユーザ定義チェーンのように、ルールセットからルールセットへと処理を飛ばすことができるのだ。バージョン5 ではあらかじめ omruleset モジュールをロードしておく必要があったが、v7では標準機能であり、モジュールをロードする必要もない。CALL は新たに書き加えられた機能で、omruleset とは別ものであり、処理速度も速くなっているのだという。v7でも omruleset はまだ使えるが、下位互換性のためだけに残されているにすぎない。面白いので CALL を使った例も示しておこう。

/etc/rsyslog.conf

module(load="imuxsock")
module(load="imklog")
module(load="imudp")
#module(load="imptcp")
 
#### GLOBAL DIRECTIVES ####
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$IncludeConfig /etc/rsyslog.d/*.conf
 
# <-- 中略 -->
 
:programname, startswith, "spice-vdagent"	/var/log/spice-vdagent.log;SpiceTmpl
 
#### RuleSet for a specific server ###
ruleset(name="Centos6uRuleSet"                     <- 2段目のRuleSetを先に作っておく
        queue.type="FixedArray"                  <- RuleSet専用のインプットキューを設ける
       ) {
    $IncludeConfig /etc/rsyslog.d/centos6u.conf_o  <- フィルタはインクルードコンフィグファイルに書く
}
  
#### Remote server log RuleSet ###
ruleset(name="RemoteUDP"
        queue.type="FixedArray"
       ) {
    $IncludeConfig /etc/rsyslog.d/remote-udp.conf_r
}
 
input(type="imudp" port="514" ruleset="RemoteUDP")

/etc/rsyslog.d/remote-udp.conf_r

$AllowedSender UDP, 192.168.1.24
if $fromhost-ip == '192.168.1.24' then call Centos6uRuleSet <- Centos6uRuleSetつまりcentos6u.conf_oの内容へ処理が飛ばされる
#& -/rlog/centos6u/messages                                 <- Centos6uRuleSetでstopされなかったエントリはここへ帰ってくるのだが...
& stop

/etc/rsyslog.d/centos6u.conf_o

if $programname startswith 'ntpd' then -/rlog/centos6u/ntpd.log
& stop
if $syslogfacility-text == 'authpriv' then -/rlog/centos6u/secure
& stop
*.* -/rlog/centos6u/messages

ちょっとだけ構造が複雑になるが、その分、ログエントリの通過する評価処理が少なくなる。リモートサーバ毎にキューが分けられるのも利点だ。複雑な振り分けをしたくなった時のために、頭の隅においておくといい技かもしれない。

ただし、Centos6uRuleSet のように独自インプットキューを備えたルールセットへ飛ばす時にはちょっと注意が必要だ。フィルタした残りのログエントリを centos6u/messages に記録するというルールを centos6u.conf_o 末尾でなく remote-udp.conf_r (コメントを付けた位置)に書くと、ntpdやauthprivファシリティを除いた残りのログが記録されるはずだが、独自キュー付き(つまり非同期処理) のルールセットは CALL されると即座にリターンを返すため、そうなるとは限らないらしい (The rsyslog “call” statement)。加えてもうひとつ- ルールセット名についてだ。CALL 先のルールセット名が "xxx-001" のようにハイフォン+数字で終わっていると、それらが断ち切られて "xxx" へ飛ぼうとしてしまうのだ。仕様だかバグだか知らないが、それを経験してから、全てのルールセット名はハイフォンを使わないことにした。

CALLによるルールセットの階層化をもう一歩推し進めると、第二階層の汎用化というところに行き着く。

/etc/rsyslog.conf

module(load="imuxsock")
module(load="imklog")
module(load="imudp" timeRequery="100")
#module(load="imptcp")
 
#### GLOBAL DIRECTIVES ####
$Umask 0000
$MaxOpenFiles 65535
 
#### RULES ####
$FileCreateMode 0600

#kern.*                                                 /dev/console
*.info;mail.none;authpriv.none;cron.none                /var/log/messages
# <-- 中略 -->
$FileCreateMode 0644
local7.*                                                /var/log/boot.log
 
$FileCreateMode 0600
:programname, startswith, "spice-vdagent"	/var/log/spice-vdagent.log;SpiceTmpl
 
#### Per-server 2nd stage RuleSet ###
template(name="PerServerNtpLogfileTpl" type="string" string="/rlog/%hostname%/ntpd.log")
template(name="PerServerAuthLogfileTpl" type="string" string="/rlog/%hostname%/secure")
template(name="PerServerMainLogfileTpl" type="string" string="/rlog/%hostname%/messages")
 
ruleset(name="PerServer2ndStage"
        queue.size=250000
        queue.dequeueBatchSize="4096"
        queue.workerThreads="4"
        queue.workerThreadMinimumMessages="5000"
        queue.type="FixedArray"
       ) {
$IncludeConfig /etc/rsyslog.d/perserver2nd.conf_o
}
 
#### Remote server log RuleSet ###
ruleset(name="RemoteUDP"
        queue.type="FixedArray"
       ) {
    $IncludeConfig /etc/rsyslog.d/remote-udp.conf_r
}
 
input(type="imudp" port="514" ruleset="RemoteUDP")

ついでながら、$FileCreateMode も入れ込んでみた。コツが要ることが分かったからだ。`$FileCreateMode 0xxx' (ビットは必ず0で始まる4オクテット) が現れてから次の $FileCreateMode が現れるまで、新規に作られるログファイルのパーミッションは 0xxx になるのだが、単に 0644 を指定しただけでは実際に作られるログは 0600 になってしまう。これは rsyslogd プロセスの umask である 0077 に規制されてしまうから。ログファイルを思い通りのパーミッションビットで作りたければ、最初のルールの現れるより手前で `$Umask 0000' でマスクをリセットしてやる必要がある ($Umask は $FileCreateMode と違って1度しか書いてはいけない-何度も書くと予期せぬ動作をする可能性があると述べられている)。また、逆に、$Umask 0000 を書いたからには、/var/log/messages などがワールドリータブルにならないよう、必ずすぐに $FileCreateMode 600 を唱えなければいけない。下の perserver2nd.conf_o で例を示すように新記述法では omfile モジュールアクション毎の属性として指定するのだが、そちらも同様に umask の影響を受ける。

/etc/rsyslog.d/remote-udp.conf_r

$AllowedSender UDP, 192.168.1.24, 192.168.1.23
if $fromhost-ip == '192.168.1.24' then call PerServer2ndStage
& stop
if $fromhost-ip == '192.168.1.23' then call PerServer2ndStage  <- 別のエージェントも簡単に追加できる
& stop

/etc/rsyslog.d/perserver2nd.conf_o

if $programname startswith 'ntpd' then
    action(type="omfile"
           dynaFile="PerServerNtpLogfileTpl"
           fileCreateMode="0600"
           dirCreateMode="0700"
           ioBufferSize="64k"
           flushOnTXEnd="off"
           asyncWriting="on"
    )
& stop
if $syslogfacility-text == 'authpriv' then
    action(type="omfile"
           dynaFile="PerServerAuthLogfileTpl"
           fileCreateMode="0600"
           dirCreateMode="0700"
           ioBufferSize="64k"
           flushOnTXEnd="off"
           asyncWriting="on"
    )
& stop
action(type="omfile"
       dynaFile="PerServerMainLogfileTpl"
       fileCreateMode="0600"
       dirCreateMode="0700"
       ioBufferSize="64k"
       flushOnTXEnd="off"
       asyncWriting="on"
)

テンプレートの働きと相まって (192.168.1.24のサーバ名が centos6u、.23がcentos6u2 だったとすると)、

/rlog/
    \_ centos6u/
        \_ ntpd.log
           secure
           messages
    \_ centos6u2/
        \_ ntpd.log
           secure
           messages

という構造がオートマチックにできてしまうのだ。サーバ名は大文字にしたい？ はいはい、テンプレート定義の "/rlog/%hostname%/ntpd.log" を "/rlog/%hostname:::uppercase%/ntpd.log" に変えてください。rsyslogのプロパティ置換機能 (PropertyReplacer) というやつだ。なぜコロンが3つも並んでいるかというと、リプレーサーの書式は

%PropName:[StartPos]:[EndPos][:Option]%

となっているから。ホスト名が centos6u2 なら、%hostname:1:7% は "centos6"、%hostname:5:$% は "os6u2" といった具合。他にも様々な変換ができるようなので興味があれば覗いてみてはいかがだろうか。

ただ、この 2ndステージの汎用化構造だと、どのエージェント発のログも、終着地であるディスクに書く手前で結局 PerServer2ndStage ルールセットに集中してしまい、エージェント毎にキューを別々にできるというメリットは犠牲になる。そこで、ここでもまた"Receiving massive amounts of messages with high performance"を参考にして、主設定ファイルにインプットキューのチューニングを入れてみた。"Understanding rsyslog Queues"も参考になる。ただし、例はただの受け売りであって、(今のところ)値を詳細に評価したわけではないので、実際に使うならテストしながら調整していただきたい。UPSや予備電源を備えていない環境の場合はリスクもある。

queue.size="250000"

メモリキューのサイズ(単位はメッセージ数)。Syslogメッセージ1つの大きさは普通 512バイトから 1kバイトの間なので、上記では 122MB～245MB のメモリが使われる計算になる。デフォルトは 10000 メッセージ。

queue.dequeueBatchSize="4096"

ドキュメントではデフォルト32と書かれているが CentOS 6.4 でデバグしたところ 16。

queue.workerThreads="4"

生成するキューWorkerの最大数。デフォルトは 1。

queue.workerThreadMinumumMessages="60000"

rsyslogdのキューWorkerは必要に応じて生成されるもので、最初にメッセージがやってきた時にはひとつだけ生成され、キューに溜まったメッセージがこのパラメータの数を超えると Worker が追加される。この例だと、次には 120000 メッセージを超えるとさらに Worker が立ち上がる。Workerが手すきになって $MainMsgQueueWorkerTimeoutThreadShutdown ミリ秒(デフォルトは60000つまり1分) 経つと、その Worker はターミネートされる。当パラメータの既定値は 100 で、$MainMsgQueueWorkerThreads が 1のままなら毒にも薬にもならないが、複数Workerスレッドを許した忙しいSyslogサーバでは、スレッド生成という重い処理が頻繁に発生すると却ってオーバーヘッドになる。

queue.type="FixedArray"

メモリキューのタイプ。これはデフォルト。エージェント側の設定で挙げる LinkedList タイプは必要な時に必要な分だけ採られるのに対して、FixedArray タイプは用がなくても或る程度メモリ領域を占めるが、パフォーマンスが高くCPUサイクルの消費も少ない。

perserver2nd.conf_o では omfile モジュールにチューニングを加えている。omfile とは、否応なしにロードされる、ローカルファイルシステム(NFSマウントも含む)へのアウトプットモジュールのこと。v5ではグローバルに設定するしかなかったが、v7ではログファイル毎に設定できる(するしかない？)ようになった。fileCeateMode と dirCreateMode は、指定するならここだということを示したかっただけで、とくに必要はない。指定するなら "600" のような3オクテット表記ではダメで必ず4オクテットで指定しなくてはならない。

asyncWriting="on"

非同期書き込みを生かすことで、バッファがキューとの2段構えにできる。デフォルト off。

flushOnTXEnd="off"

Off にすると、メッセージ毎(？)にバッファをフラッシュするのはやめて、バッファが満たされてからファイルへ吐き出す。デフォルト on。

iOBufferSize="64k"

バッファサイズ。デフォルトはわずか 4k。

以下は、グローバルディレクティブセクションに書くステートメント。レガシーディレクティブしか見つからない。

$MaxOpenFiles 65535

文字通り。このステートメントに基づいて、rsyslogd は起動時に setrlimit() システムコールを使い `ulimit -Sn xxx' 相当の設定を行う。当然ながら、ソフトリミットはあらかじめ設定されたハードリミットを超えることはできない。あらかじめシステムの ulimit設定で nofile を充分大きくしておく必要がある (これだけはやっておきたいシステム設定 参照)。オープンファイルには、実際に書き出すログファイルだけでなくネットワークソケットなども含まれる。

同じくグローバルセクションで使っている timeRequery は次項で。

さらに他のチューニング方法

キューやバッファ絡みの他にも、チューニングの要素はある。きわめてリモートログ取扱量の多いSyslogサーバなら、検討する価値がある。

imudpモジュールの timeRequery オプション

UDPインプットモジュール特有のパラメータ。Syslogソフトウェアにとって、ローカルのシステム時刻を取得する行為は馬鹿にならないオーバーヘッドを伴うもののようだ。このパラメータによって、メッセージ何本毎にシステム時刻を取得し直すかを制御できる。デフォルトは 2メッセージに 1回。既定で使われる、rsyslog にハードコードされた RSYSLOG_TraditionalFileFormat テンプレートでは、冒頭の日時は rsyslogd への着信日時 (%timegenerated%) ではなく、Syslogメッセージ内に格納された生成日時 (%timestamp% つまりSyslogメッセージのTIMESTAMPフィールド) なので、実際にファイルに記録される日時に影響はないはず。なお、RSYSLOG_TraditionalFileFormat テンプレートはソースコードの tools/smtradfile.c で定義されている。

syslogd起動オプション -x の使用

syslogd起動時に -x オプションを渡すと、syslogd のDNS検索を抑止できる。ただし、コンフィグも名前解決が発生しないように留意して書く必要が生じる。使うなら /etc/sysconfig/rsyslog の SYSLOGD_OPTIONS 変数に加えておけばよい。

DNSキャッシュの実装

-x オプションを利用する代わりに、Syslogサーバ上にDNSキャッシュを実装すれば、いちいち別のDNSサーバに問い合わせるよりはオーバーヘッドが小さくて済む。djbdns の dnscache や、標準パッケージの dnsmasq をセットアップすればよい。

コンフィグのデバグ

自分の書いたコンフィグが意図通りに解釈されているか確かめるには、rsyslogd をデバグモードで起動してみる。

root# service rsyslog stop
root# RSYSLOG_DEBUG=DEBUG RSYSLOG_DEBUGLOG=/var/tmp/rsyslog-debug.log /sbin/rsyslogd -x
root# kill -TERM $(cat /var/run/syslogd.pid)
root# ps axw |grep rsyslogd

ログは標準出力にも出力されるので RSYSLOG_DEBUGLOG変数は指定しなくてもいいが、指定すればファイルにも記録されるので調査がしやすい。RHEL/CentOS だと、普段 SysVinit から起動する時には /etc/sysconfig/rsyslog の SYSLOGD_OPTIONS に入れてあるコマンドラインオプションが拾われて付加されるので、正確を期すならデバグの時にも指定した方がよい(上記の例での -x)。

記載法ミニリファレンス

大文字小文字の区別について

• レガシー形式の $Directive は大文字小文字を区別しない。
• プロパティ名は、レイナースクリプトの条件評価、レガシーのプロパティベース形式の条件評価、テンプレートの構成文字列内のいずれで使う時も、大文字小文字を区別しない。
• 設定ファイル内で使うオブジェクト的な定義名 (テンプレートやルールセットなど) は大文字小文字を正確に記述したほうが気持ちいい。実際は、テンプレート名は大文字小文字が区別されるが、ルールセット名は区別されない。

条件フィルタでの値のクォートについて

• レイナースクリプト形式では、文字列比較の時は値を 'シングルクォート' しなければならない。数値比較の時はクォートなしでも可。ダブルクォートは常にダメ。文字列比較か数値比較かはプロパティの性質による。例： $syslogfacility は数値、$syslogfacility-text は文字列。
• プロパティベース形式では、値は "ダブルクォート" しなければならない。数値プロパティだとしても。

レイナースクリプトの比較演算子

評価を反転する not も使える。ただし "not $A == 'B'" は (not $A) == 'B' と評価されてしまうため "not ($A == 'B')" と書かなければならず、だったら単純に "$A != 'B'" と書いた方がマシ、と注意書きあり。contains などと組み合わせる場合は "if not ($A contains 'B')" と書くべきと思われる。

rsyslogで使用できるプロパティ

Syslogもひとつのプロトコルである。好き勝手な文字や数字の羅列が送られてくるわけではないし、我々が普段ログファイルで見るままのカタチで送られてくるわけでもない。例えば、ファシリティとシビアリティは然るべき計算をもって1～3桁の数字にまとめて '<' と '>' で挟んで送れ(このフィールドを PRI [プライオリティ] と呼ぶ)とか、そういった種々のフィールドを何をデリミタにしてどういう順番で並べろという規格が決まっている。RFC5424 (RFC3164を置き換え) が Syslogプロトコルの基本定義。RFC5426 が Syslog over UDPの仕様。さらに RFC5425 で TLS による暗号化送受信の規格が定義されている。

RFC5424を書いたのは、何を隠そう、rsyslog 開発の中心人物 レイナー・ゲルハルト氏その人である。ゲルハルト氏はドイツのシステムコンサルタント/ソフトウェア会社 Adiscon の代表でもある。

とはいえ、現在も、そして今後もかなり長らく、実世界では、RFC5424フォーマットとRFC3164フォーマットのメッセージが入り乱れて使用されていくだろう。そこで rsyslog は、複数のパーサーモジュールで順繰りにメッセージを評価して、RFC5424形式のメッセージなのかRFC3164のメッセージなのかを判定してフィールドをプロパティに割り当てる。デフォルトでは、先に評価するのは pmrfc5424 パーサーモジュールで、それが失敗すると pmrfc3164 でパースが行われる。RFC3164は5424よりずっと規則が緩いので、先に pmrfc3164 で評価するとどのメッセージもRFC3164フォーマットと判定されてしまうからだという。

• レイナースクリプトの条件評価式で使う場合は $PropName の形で使う。
• プロパティベース形式の条件評価に使う時は何の添え字も付けない。
• テンプレートの構成文字列内では %PropName% の形で使う。

Syslogメッセージの属性とは直接関係のないその他のプロパティ。頭の $ もプロパティ名の一部であり、例えばテンプレートでなら %$myhostname% といった具合に使う。

エージェント側の設定

/etc/rsyslog.conf (レガシー記述法)

$ModLoad imuxsock
$ModLoad imklog
 
#### GLOBAL DIRECTIVES ####
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$IncludeConfig /etc/rsyslog.d/*.conf
 
#### RULES ####
#kern.*                                                 /dev/console
*.info;mail.none;authpriv.none;cron.none                /var/log/messages
# <-- 通常のローカルログフィルタ記述が続く。略 -->
 
# ### begin forwarding rule ###
$WorkDirectory /var/lib/rsyslog #<- ディスクキューとして使うディレクトリ
$ActionQueueFileName fwdRule1   #<- キューチャンクファイルの接頭句。実際のファイルはfwdRule1.0000001といった名前で作られる
$ActionQueueMaxDiskSpace 200m   #<- 補助キュー用ディスクスペースの容量制限。本番サーバなら数g などできるだけ大きい方がよい
$ActionQueueSaveOnShutdown on   #<- キューWorkerの終了時にまだメモリ上に処理残のキューがあればディスクキューに保存する
#$ActionQueueHighWaterMark 8000 #<- 補足説明参照
#$ActionQueueLowWaterMark 2000  #<- 補足説明参照
$ActionQueueType LinkedList     #<- LinkedLisタイプのtメモリキューを作成
#$ActionResumeInterval 60       #<- リトライ間隔の初期値(秒)
$ActionResumeRetryCount 60      #<- リトライ回数。ローカルにも書かれるので、Syslogサーバが長らくアクセス不能な時はあきらめる。デフォルト見本は -1(無制限)
*.* @192.168.1.25:514           #<- 全ログをSyslogサーバへUDP送信する
#*.* @@192.168.1.25:514         #<- TCPの場合は@を2つにする
#if $programname startswith 'ntpd' then @192.168.1.25:514   #<- ntpdとntpdateのログだけ送るならこんな感じ
# ### end of the forwarding rule ###
 
# A template to for higher precision timestamps + severity logging
$template SpiceTmpl,"%TIMESTAMP%.%TIMESTAMP:::date-subseconds% %syslogtag% %syslogseverity-text%:%msg:::sp-if-no-1st-sp%%msg:::drop-last-lf%\n"
 
:programname, startswith, "spice-vdagent"	/var/log/spice-vdagent.log;SpiceTmpl

核心の`*.* @192.168.1.25:514' については特に説明は要らないだろう。

その上の送信キューについて少し補足しておく。rsyslogオフィシャルドキュメントの他に、RHEL7 のドキュメントが参考になる。送信先のSyslogサーバがオフラインになると、送信すべきログは出力キューにバッファされる。RHEL/CentOS 6 でインストールされるサンプルコンフィグ(上記もそれを元にしている) に書いてある送信キューは、ディスク補助付きInメモリキュー(Disk-Assisted In-memory Queue) と呼ばれるタイプ。メインキューはメモリで、それが閾値に達した場合だけ補助キュー(=ディスクキュー) にバッファされ始める。閾値とはメモリ上のログメッセージの数が $ActionQueueHighWaterMark に達した時で、それが $ActionQueueLowWaterMark 値に下がるまで補助キューへ吐き出される。上でコメントとして書き添えた値は暗黙のデフォルト閾値だ。

では、キューが一杯になったらどうなるのか。rsyslogd は送信リトライ10回毎に $ActionResumeInterval (秒)を延ばしながら、最大 $ActionResumeRetryCount 回まで送信先の復帰を待つ。そしていよいよメモリキューがいっぱいになると、rsyslogd はまずログの受け入れ速度を落とし(スロットル)、ログのシビアリティなどに基づいて古いエントリを捨てつつ、どんどん補助キューへエントリを吐き出す。しかし、いつまでも logソケットなどをスロットルし続ければシステムのストールにつながりかねない。メモリキューも補助キューも満杯のまま状況が改善せず $ActionQueueTimeoutEnqueue ミリ秒 (デフォルト 2000) 経過すると、遂に最後の手段として、新着のログを破棄し始める。

ファイルを監視してSyslogに取り込む - imfileインプットモジュール

rsyslog v5 の時から既にあったようなのだが、imfile という面白いインプットモジュールがある。これは、タイムスタンプも伴わない平易なテキスト出力ファイルを定期的にポーリングし、エントリを syslog へインポートする働きをする。もちろん、通常のログ同様にフィルタを使用してログファイルの振り分けができ、ログエントリは立派に syslog のフォーマットに則って書かれる。ログエントリの TIMESTAMP は、imfileモジュールが監視先ファイルからそのエントリを読み取った日時だ。さらに興味深いのは、監視先ファイルがローテーションされることを見越して作られている点だ。

例えば、2つのインターネットサイトを10分間隔でプローブしてHTTPレスポンスコードをそれぞれ /var/cache/siteprobe/myportal と /var/cache/siteprobe/myhome というファイルに出力しているとしよう。テキストの出力フォーマットは下記のようなものだとする。フィールドの区切りはスペース。第2フィールドにこのサイト試験のタイトルである "myportal" と "myhome" が必ず入るのがキモで、これを基準に rsyslog のテンプレート機能でログを振り分けるという趣向だ。

監視先ファイル siteprobe/myportalに記録されるエントリ：

200 myportal http://www.myportal.cxm/index.html

監視先ファイル siteprobe/myhomeファイルに記録されるエントリ：

200 myhome http://www.myhome.cxm/index.html

rsyslog のコンフィグはこんな塩梅になる。

/etc/rsyslog.conf

module(load="imuxsock")
module(load="imklog")
module(load="imfile" pollingInterval="20")      <－監視先ファイルのポーリング間隔の既定値は10秒。20秒にするならこのように書く
 
#### GLOBAL DIRECTIVES ####
$Umask 0000                       <-前述の「第2階層の汎用化」のところを参照のこと
$WorkDirectory /var/lib/rsyslog   <-必要。下記 siteprobe.conf_f の中で解説する
 
#### RULES ####
$FileCreateMode 0600

#kern.*                                                 /dev/console
*.info;mail.none;authpriv.none;cron.none                /var/log/messages
# <-- 中略 -->
 
#### File import module demo ###
$IncludeConfig /etc/rsyslog.d/siteprobe.conf_f

/etc/rsyslog.d/siteprobe.conf_f

template(name="siteprobeLogfileTpl" type="string" string="/var/log/siteprobe/%msg:F,32:2%")
 
ruleset(name="siteprobeRuleset"
        queue.type="FixedArray"
       ) {
    if $programname == 'siteprobe' then
        action(type="omfile"
               dynaFile="siteprobeLogfileTpl"
               fileCreateMode="0644"
               dirCreateMode="0755"
               flushOnTXEnd="off"
               asyncWriting="on"
              )
    & stop
}
 
input(type="imfile" file="/var/cache/siteprobe/myportal" tag="siteprobe:" statefile="siteprobe-myportal" ruleset="siteprobeRuleset")
input(type="imfile" file="/var/cache/siteprobe/myhome" tag="siteprobe:" statefile="siteprobe-myhome" ruleset="siteprobeRuleset")

template(name=...)

ログファイル名を動的に計算するためのテンプレート。string="..."の最後の %msg:F,32:2% は前に述べたプロパティリプレーサーのトリックのひとつ。F はフィールド切り出し命令で、`F,32' は「文字コード32(10進)つまりスペースをデリミタと見なして」の意、その後の 2 が「第2フィールド」という意味。imfileでは、監視先ファイルの1行全体が msg プロパティとして取り込まれる。文字コードは16進では受け付けてくれないことに注意。

if $programname == 'siteprobe' then

siteprobe.conf_f ファイル末尾の input(...) での tag="...:" に合わせる。

input(type="imfile" ...)

imfileモジュールを実際に駆動させるのがこの行。ここで書いたのは基本的に全て必須パラメータで、この他にも facility, severity などのパラメータがある。file は監視先テキストファイルの絶対PATH。tag は、通常なら各プログラムがログメッセージに載せてくる TAG フィールドをエミュレートするために必要で、通常、programname + ':' の形で書く。statefile は、imfileモジュールがどのファイルのどこまでをいつインポートしたかを記録するファイルで、監視先ファイル毎に別々にしなくてはいけない。これがあるおかげで、rsyslogd を再起動している間に新たなエントリが監視先ファイルに追加されたとしても取りこぼしが起きない。ステートファイルは rsyslogd の $WorkDirectory に作られるはずなのだが、RHEL/CentOS 6.6の rsyslog 7.4 で実際に検証したところ、暗黙に定義された $WorkDirectory を無視するという不具合がimfile モジュールにはあるようで、なんと / (ルート)直下にステートファイルが作られてしまうのだ(Ubuntuのバグレポートにも載っているのを見つけた)。その回避のため、imfile を使う場合は必ずグローバルディレクティブ $WorkDirectory で明示的に定義すべきだ。なお、$WorkDirectory は複数回唱えてもよく、ルールセット毎にアウトプットキュー作成ディレクトリを分けるのに利用している例もある。

最後に、監視先ファイルのローテーションについて触れておく。imfile は監視先のファイルをポインタで追跡しており、ローテーションによってファイル名が代わるとそれを検知し、前のファイルの内容を全てインポートし終えてから新しいファイルへポインタを切り替える。それ故、注意しなくてはいけないのは、監視先ファイルのローテーションは rsyslogd が稼働している時に行わなくてはいけないという点だ。エントリはインポート先syslogファイルへどんどん保存されていくわけで、監視先ファイルは短期間でローテーションしたほうがディスクが節約できる。ローテーション世代もカレント+1世代で充分だ。ここで題材にしている仮想のサイトプローブシェルスクリプトに組み込むなら、例えば下記のような処理でよい。

if [ $LOGCLEARINTVL -gt 0 -a "$COUNT" -gt $LOGCLEARINTVL ]; then
  [ -f ${LOG}.1 ] && mv -f ${LOG}.{1,2}
  mv -f $LOG{,.1} &>/dev/null
  rm -f ${LOG}.2
  COUNT=1
fi