CentOS 6.7 の rsyslog で他のサーバ等から syslog を TCP/UDP で受け取り、ログを PostgreSQL へ登録しようとした時のこと。
環境は以下の通り。全てのサーバは同一セグメント内にある。
【syslog を受け取るサーバ】
CentOS 6.7
2.6.32-573.8.1.el6.x86_64
rsyslog-5.8.10-10.el6_6.x86_64
rsyslog-pgsql-5.8.10-10.el6_6.x86_64
postgresql-server-8.4.20-4.el6_7.x86_64
【syslog を送るサーバ】
・1台目
CentOS 5.11
2.6.18-407.el5PAE
rsyslog-3.22.1-7.el5
・2台目
CentOS 6.7
2.6.32-573.8.1.el6.x86_64
rsyslog-5.8.10-10.el6_6.x86_64
・3台目
CentOS 7.1
3.10.0-229.el7.x86_64
rsyslog-7.4.7-12.el7.x86_64
syslog を受け取るサーバでは、rsyslog-pgsql モジュールを使い、ログを PostgreSQL のテーブルへ登録する。
PostgreSQL では、予め以下のようなテーブルを用意してある。
syslog_db=> \d log_tbl
テーブル "public.log_tbl"
カラム | 型 | 修飾語
-------------+--------------------------------+-----------------------------------------------------
id | integer | not null デフォルト nextval('log_id_seq'::regclass)
generated | timestamp(0) without time zone |
facility | smallint |
priority | smallint |
hostname | text |
programname | text |
message | text |
syslog を受け取るサーバの /etc/rsyslog.conf の主な設定は以下の通り。
※後述しますが、下記の設定は$template 行の末尾が誤っています。
$ModLoad imudp
$UDPServerRun 514
$AllowedSender UDP, 127.0.0.1, 192.168.1.0/24
$ModLoad imtcp
$InputTCPServerRun 514
$AllowedSender TCP, 127.0.0.1, 192.168.1.0/24
$ModLoad ompgsql
$template Mypgsql,"INSERT INTO log_tbl (generated, facility, priority, hostname, programname, message) values ('%timegenerated:::date-rfc3339%', %syslogfacility%, %syslogpriority%, '%hostname%', '%programname%', '%msg%')",sql
*.* :ompgsql:localhost,syslog_db,db_user,db_pass;Mypgsql
rsyslog-pgsql にバンドルされているデフォルトのテーブル定義（/usr/share/doc/rsyslog-pgsql-5.8.10/createDB.sql）を使わず、自分で定義したテーブルへデータを登録するため、Mypgsql というテンプレートにSQLを定義。
これで syslog のデータを受け取ったものをDBへINSERTしていく。
この環境でログの受信をテストしていると、CentOS 5.11 のサーバを再起動した時に、受け取った側のサーバの rsyslog プロセスのCPUが高くなり、暫く待っても収まらない問題に遭遇。
送り側のOSの問題か切り分けるだめ、他のCentOS 6/7のサーバを再起動しても、上記と同じく問題が発生したので、受け側の問題と推測。
CentOSが起動する際に送られる syslog を受け取った側の rsyslog がおかしくなるようだった。
暫く待ってもDBの処理が終わらず、以下のエラーを出してDB処理が終了する。
Dec 13 11:52:59 syslog_srv rsyslogd: db error (1): no connection to the server
3台のサーバから、シェルでfor/loggerを使って10000万回のテストメッセージを出力し、TCP/UDPで転送してみても再現できなかったので、受け側のrsyslog の負荷の問題ではなさそうだった。
また、DBへの登録はせず、TCP/UDPで受け取ったsyslog をテキストへ保存すると問題は発生しない。
/var/log/messages のログを眺めると、CentOS起動時のログにシングルクォートが。
/etc/rsyslog.conf に設定したテンプレート部分のSQL文が、エスケープされていないのではないかと思い、logger コマンドで以下を試した。
$ logger test r\"syslog
→test r"syslog でDBに登録される
$ logger test 'r"syslog'
→test r"syslog でDBに登録される
$ logger test r\'syslog
→DBに登録されない
$ logger test "r'syslog"
→DBに登録されない
犯人は、シングルクォートでした。
公式ドキュメントを見ると、SQL を指定する際は書式が2種類ある。
http://www.rsyslog.com/doc/v5-stable/configuration/templates.html
sql - format the string suitable for a SQL statement in MySQL format. This will replace single quotes (“’”) and the backslash character by their backslash-escaped counterpart (“\’” and “\\”) inside each field. Please note that in MySQL configuration, the NO_BACKSLASH_ESCAPES mode must be turned off for this format to work (this is the default).
stdsql - format the string suitable for a SQL statement that is to be sent to a standards-compliant sql server. This will replace single quotes (“’”) by two single quotes (“’‘”) inside each field. You must use stdsql together with MySQL if in MySQL configuration the NO_BACKSLASH_ESCAPES is turned on.
Either the sql or stdsql option must be specified when a template is used for writing to a database, otherwise injection might occur. Please note that due to the unfortunate fact that several vendors have violated the sql standard and introduced their own escape methods, it is impossible to have a single option doing all the work. So you yourself must make sure you are using the right format. If you choose the wrong one, you are still vulnerable to sql injection.
これらはエスケープ方法が異なる。
sql の場合、 ' は \ でエスケープされる。MySQL で利用。
stdsql の場合、 ' は '' でエスケープされる。
PostgreSQLの場合、stdsql を使わなければならない。
さっそく、/etc/rsyslog.conf の $template 行の末尾を sql → stdsql に修正。
$ModLoad ompgsql
$template Mypgsql,"INSERT INTO log_tbl (generated, facility, priority, hostname, programname, message) values ('%timegenerated:::date-rfc3339%', %syslogfacility%, %syslogpriority%, '%hostname%', '%programname%', '%msg%')",stdsql
*.* :ompgsql:localhost,syslog_db,db_user,db_pass;Mypgsql
rsyslog サービスを再起動して、syslog 送信側の各サーバを再起動してみると、受け側の rsyslog はCPUの負荷も上がらず、DBにも正常に登録された。
そもそも何故、設定ファイルに sql と書いたかというと、、、
以前同じように syslog をDBに登録した時はMySQLを使った事があり、今回はその時の構築メモを見ながらPostgreSQLを使ったのでハマった。
なお、rsyslog-pgsql にバンドルされている /usr/share/doc/rsyslog-pgsql-5.8.10/createDB.sql を使うと構文エラーが出る。
$ psql -f /usr/share/doc/rsyslog-pgsql-5.8.10/createDB.sql
psql:/usr/share/doc/rsyslog-pgsql-5.8.10/createDB.sql:1: ERROR: "'Syslog'"またはその近辺で構文エラー
行 1: CREATE DATABASE 'Syslog' WITH ENCODING 'SQL_ASCII';
^
psql:/usr/share/doc/rsyslog-pgsql-5.8.10/createDB.sql:2: \connect: FATAL: データベース"Syslog"は存在しません
PostgreSQL では大文字と小文字を区別する場合、文字をダブルクォーテーションで括るので、テンプレートを修正する。
ついでにDBのエンコードも環境に合わせる。
CREATE DATABASE 'Syslog' WITH ENCODING 'SQL_ASCII';
↓
CREATE DATABASE "Syslog" WITH ENCODING 'UTF8';
これでrsyslog-pgsql にバンドルされているテーブル定義へログを登録できるようになるが、カラムを自分で定義したい場合には以下を参考にSQLを定義すると良い。
http://www.rsyslog.com/doc/v5-stable/configuration/templates.html
http://www.rsyslog.com/doc/v5-stable/configuration/properties.html
http://www.rsyslog.com/doc/v5-stable/configuration/property_replacer.html
上記は、rsyslog v5.x の場合で、7系や8系は、URLが異なる。
CentOS 6.7 では、rsyslog7 パッケージが利用できるので、7系のリンクもメモ。
http://www.rsyslog.com/doc/v7-stable/configuration/templates.html
http://www.rsyslog.com/doc/v7-stable/configuration/properties.html
http://www.rsyslog.com/doc/v7-stable/configuration/property_replacer.html
