#navi_header|技術| お仕事で、Javaからsyslogdにログ出力する必要が生じました。しかも、Solaris上のsyslogです。 Log4jのAppenderで、syslogのプロトコルを用いてネットワーク接続で出力するSyslogAppenderがあるとの事なので、Solaris10もどうにかインストールできましたので試してみました。 #outline ---- * 実験用Javaソース log4j-1.2.13.jarを使用した。 ** test.log4j.SyslogSample.java package test.log4j; import org.apache.log4j.Logger; public class SyslogSample { public static void main(String[] args) { Logger logger = Logger.getLogger("syslog"); logger.debug("--debug--"); logger.info("--info--"); logger.warn("--warn--"); logger.error("--error--"); logger.fatal("--fatal--"); } } ** log4j.properties log4j.appender.syslog=org.apache.log4j.net.SyslogAppender log4j.appender.syslog.Facility=local5 log4j.appender.syslog.SyslogHost=192.168.250.50 log4j.appender.syslog.FacilityPrinting=true log4j.appender.syslog.layout=org.apache.log4j.PatternLayout log4j.appender.syslog.layout.ConversionPattern=AA%5p %c{1} - %m%n log4j.appender.console=org.apache.log4j.ConsoleAppender log4j.rootLogger=console, syslog * 実験用Solaris10+syslogd環境整備 Solaris上でのsyslog設定やサービスの再起動は初めてだったので、色々と試行錯誤になってしまった。 ちなみに、ローカルでの確認はloggerコマンドを用いて次のようにした。 logger -p local5.notice -t HOGE abcdefg ** syslogd(というよりサービス)の再起動 Solaris10では、"SMF(Service Management Facility)という機能により、様々なサービスの起動・停止・再起動・依存関係を統合して管理できるようになった。今回、設定ファイル変更に伴う再起動を行うsyslogdも、SMFを通じて再起動をする。 *** 起動中のサービスの一覧 [root@basara /]# svcs STATE STIME FMRI legacy_run 19:21:23 lrc:/etc/rcS_d/S50sk98sol legacy_run 19:22:23 lrc:/etc/rc2_d/S10lu ... online 22:21:37 svc:/system/system-log:default offline 19:21:08 svc:/application/print/ipp-listener:default offline 19:22:12 svc:/application/print/rfc1179:default *** syslogの所属するサービスは何か？ 通常なら次のコマンドであるプロセスを対象としているサービス名を取得できる。 [root@basara /]# svcs -p sendmail STATE STIME FMRI online 19:22:23 svc:/network/smtp:sendmail 19:22:23 376 sendmail 19:22:23 378 sendmail しかし、syslogdに関してはこれが利用できない。 *** プロセス名からサービス名(というのか？)を取得してみる。 [root@basara /]# svcs -p syslogd svcs: パターン 'syslogd' がどのインスタンスとも一致しません STATE STIME FMRI *** manページに載っている場合もある。 そこで、ふとsyslogdのmanを確認していると・・・ $ man syslogd ... System Administration Commands syslogd(1M) svc:/system/system-log:default Administrative actions on this service, such as enabling, disabling, or requesting restart, can be performed using svcadm(1M). The service's status can be queried using the svcs(1) command. *** サービスの状態と詳細を確認する。 というわけで、 [root@basara /]# svcs -l system/system-log:default fmri svc:/system/system-log:default name system log 有効 true 状態 online next_state none state_time 2006年07月02日 (日) 22時21分37秒 logfile /var/svc/log/system-system-log:default.log リスタータ svc:/system/svc/restarter:default contract_id 109 dependency require_all/none svc:/milestone/sysconfig (online) dependency require_all/none svc:/system/filesystem/local (online) dependency optional_all/none svc:/system/filesystem/autofs (online) dependency require_all/none svc:/milestone/name-services (online) これがsyslogdのようである。下記参照。 - http://solaris-user.com/solaris10_smf/manual_smf.html *** syslogd再起動成功 以上より、次のコマンドでsyslogdを再起動できた。 # svcadm restart system/system-log:default ** ミスその１ まず、/etc/syslog.confに次のようなエントリを追加してみた。 local5.* /var/log/log4j.log 以下の点で間違い。 + レベルに"*"は使用不可。レベル大小によるマッチングがあるのだから、全てを出したいのであれば"debug"を使用する。 + "facility.level"と、ファイル名との間がスペース。他のエントリを見てみると基本、TAB区切り。 ちなみに先の間違っているエントリを使用すると、次のようなログが/var/adm/messagesに出る。 Jul 2 22:10:06 basara syslogd: line 18: unknown priority name "* /var/log/log4j.log" ** ミスその２ ログファイルを作らずに、loggerコマンドなどで試してみたところ、/var/adm/messagesに以下のログが出力された。 Jul 2 22:18:07 basara syslogd: /var/log/log4j.log: ファイルもディレクトリもありません。 そこでtouchで作成してみたところ、まだ上記ログが出る。syslogdを再起動してみたら直った。 ** syslogdで外部接続を許可する。 次のファイルで、外部接続の許可を制御できる。 /etc/default/syslogd デフォルトで「LOG_FORMAT_REMOTE=YES」がコメントアウトされており、また、それがデフォルトである。禁止したい場合はNOを設定する。今回はリモートのJavaからの出力を試みるので、デフォルトのママにしておく。 ** 成功 上記の注意点を参考に、syslog.confの変更およびログファイルをtouchにより作成し、syslogdの再起動を行ったところ、loggerコマンドで以下のようなログを出力できた。 # tail /var/log/log4j.log Jul 2 22:19:20 basara HOGE: [ID 702911 local5.notice] abcdefg * Log4j + syslogd(Solaris10) ** リモートのJavaより、syslogdに飛ばす。 以下に、実際に出力された模様を示す。 # (このタイミングでWindows側のJavaからSyslogSampleを実行) Message from syslogd@[192.168.250.100.11.180] at Sun Jul 2 22:23:24 2006 ... [192.168.250.100.11.180] local5:AAFATAL syslog - --fatal--^M # tail /var/log/log4j.log Jul 2 22:21:40 basara HOGE: [ID 702911 local5.notice] abcdefg Jul 2 22:23:24 [192.168.250.100.11.180] local5:AADEBUG syslog - --debug--^M Jul 2 22:23:24 [192.168.250.100.11.180] local5:AA INFO syslog - --info--^M Jul 2 22:23:24 [192.168.250.100.11.180] local5:AA WARN syslog - --warn--^M Jul 2 22:23:24 [192.168.250.100.11.180] local5:AAERROR syslog - --error--^M Jul 2 22:23:24 [192.168.250.100.11.180] local5:AAFATAL syslog - --fatal--^M 以下の点がローカルのloggerと異なっている。 + リモートIPが記載される。 + facilityの表記のみになっている。 + Windows上のJavaから出力した為か、末尾改行で"^M"が付いてしまっている。 + loggerコマンドの"-t"オプションに相当するパラメータが無い。 ** ローカルのJavaより、syslogdを飛ばす。 log4j.propertiesを修正し、SyslogHostを"localhost"にしてSolaris10上で実行してみる。 [msakamoto@basara java]$ java -cp .:./lib/log4j-1.2.13.jar test.log4j.SyslogSample Message from syslogd@localhost at Sun Jul 2 22:58:05 2006 ... localhost local5:AAFATAL syslog - --fatal-- 実行側のコンソールに、fatalメッセージが割り込んでいるのが分かる。これは正常である。 # tail /var/log/log4j.log Jul 2 22:58:05 localhost local5:AADEBUG syslog - --debug-- Jul 2 22:58:05 localhost local5:AA INFO syslog - --info-- Jul 2 22:58:05 localhost local5:AA WARN syslog - --warn-- Jul 2 22:58:05 localhost local5:AAERROR syslog - --error-- Jul 2 22:58:05 localhost local5:AAFATAL syslog - --fatal-- こちらがsyslogdの出力しているログである。"AA"以降がJava側で指定しているメッセージフォーマットである。 やはり、ローカルのloggerとフォーマットが異なる。 * 結論 Log4jのSyslogAppender経由で出力するsyslogは、ローカルでloggerコマンドにより出力するログ形式とはフォーマットが異なる。 ただし、上記は自分で設定したfacilityに出力した場合であり、今回仕事ではuser.errorで固定で出力する。その場合は、まだ実験していない。 -------- 余談だが、この実験を終えた後、「今日一日installからここまでずう～～っと動かしっぱなしだったな」と、風呂にはいるのを兼ねて一旦PCを落とした。 その後再起動し、VMwareからSolaris10を立ち上げたら '' ネットワークカードの初期化に失敗してるし。 '' 急いでグラフィカルログインから（こういうときがあるから迂闊にコンソールにできない。いや、単にLinuxでいうstartxに該当する手順を知らないだけなんだけど）、svcsを叩いてみたら '' 見事に network/physical:default が offline になってるし。 '' あわてて /etc/inet/hosts, ipnodes を確認してみたら '' localhostだけになってて、自分で指定したホスト名のエントリがいつの間にか消去されてるし。 '' ・・・誰だ？自分じゃないはず。・・・まさか、Sun Studio 11とかそのパッチの影響か・・・？確かにSun Studio 11を入れた頃には一通り環境が整いつつあったので、再起動はかけていない。 とりあえず急いで、対応する.savedファイルを確認してホスト名のエントリを書き戻す。 # svcadm enable -r network/physical:default をやろうとすると((-rというのはdependsするサービスもまとめて起動するオプション))、maintenanceモードに入っているからと怒られる。 ん？ひょっとして # svcadm reflesh network/physical:default したのがまずかったか？もう一度svcsしてみたら確かに"maintenance"と表示されてしまっている。 # svcadm clear network/physical:default したらmaintenanceモードが消えたので、もう一度 enable してみる。 これで、ようやく"online"になってくれた・・・。念のため再起動かけてみると、無事指定しているIPアドレスが取得できたようで、SSHからもログインできた。 あ～～・・・焦った・・・。 #navi_footer|技術|