log4j2でrsyslogにTCP転送

log4j2でrsyslogにログ転送するのを試していましたが、思わずはまったのでメモ。

環境

• rsyslogのホスト：CentOS 6
• rsyslogのバージョン：CentOS 6の標準バージョン（v5）

転送元のプログラム

ただログを飛ばしたいだけなので、こんなので十分。

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Main {
  private static final Logger log = LogManager.getLogger(Main.class);

  public static void main(String... args) {
    log.debug("debug message");
    log.info("info message");
    log.warn("warn message");
    log.error("error message");
  }
}

log4j2.xmlの設定。
https://logging.apache.org/log4j/2.x/manual/appenders.html#SyslogAppenderを参考に。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <Syslog name="syslog" host="sysloghost" port="514" protocol="TCP" />
  </Appenders>

  <Loggers>
    <Root level="trace">
      <AppenderRef ref="syslog" />
    </Root>
  </Loggers>
</Configuration>

転送先のrsyslog設定

単にデフォルトの設定からコメントアウトされている以下設定を有効にするのみ。

$ModLoad imtcp
$InputTCPServerRun 514

はまったこと

UDPで送れることは確認できていたので、単に「protocol=TCP」に変えるだけと油断していました。
なんでか、ファイルに出力されない。UDPだと出ているのに、TCPにした途端に出ない。。

調べてみるとSELinux周りで、514/tcpはrsh用なので、rsyslogでは601/tcpじゃないと、みたいなのを見つけたけれども、そもそもPermissiveなのでSELinux関係ない。
もちろん、iptablesは無効。
rsyslogを「rsyslog -d -n」でデバッグモード起動してみると、確かにTCPでも受信はしているけれど、その後のログ出力に至っていない。
TCP転送自体の問題か？と思って、2ノード間でのログ転送環境を用意して試したところ、ちゃんとTCP転送はされている。
なんでかなぁ・・と調べては眠くなって寝て、、を繰り返して3日目にして、ようやく解決。

結局のところ

TCP転送ができているということは、サーバ側の設定には問題なしと見て間違いない。となるとクライアント側ということになる。
とは言え、log4j2なんて枯れた部類のはずで、今さらTCP転送できないなんてことはないはず。
tcpdumpやデバッグログを見ていると、データの受信はできているようだが、ログ出力には至っていないということは、サーバ側が「ログ出力してよし」という判断に至っていないものと予想する。
つまり、終端文字的なものを受け取っていないので、サーバ側が「まだデータが来るはず」と思って待っている状態なのだろうという読みです。
確かに、ほかのAppenderでログフォーマット指定する時、わざわざPatternLayoutに「%n」で改行コード入れるよねぇ、、ということで、再度ドキュメントを確認すると「newLine」なる属性が。

そんなわけで、log4j2.xmlを以下のように変えて、無事ログ転送を確認できましたとさ。

  <Appenders>
    <Syslog name="syslog" host="sysloghost" port="514" newLine="true" protocol="TCP" />
  </Appenders>

UDPの時はなんかそれっぽく転送されていることが話をややこしくした感じです。。