[CentOS6][SOS JobScheduler] JobSchedulerのログを rsyslog に出力する


Create: 2014/07/13
LastUpdate: 2014/07/13
[ メニューに戻る ]

ここでは、JobScheduler のログを rsyslog に出力する方法を紹介します。

手順は、「How to configure JobScheduler logging」 を参考にしました。
なお、JobSchedulerは、1.5.3253 (Linux用の64bit)を使用し、CentOS6.5(64bit)で動作確認しています。

JobScheduler は、ログの出力を log4j で制御できます。

たぶん、デフォルトで log4j を使用可能な設定になってると思いますが、 factory.ini に以下の赤字部分の設定があれば log4j を使用できます。
[java]
class_path              = ${SCHEDULER_HOME}/lib/*.jar:${SCHEDULER_HOME}/lib/hibernate/*.jar:${SCHEDULER_HOME}/lib/jetty_ext/*.jar:${SCHEDULER_HOME} /lib/log/log4j/*.jar

JobScheduler は、任意の log4j 設定ファイルを使うように設定できます。
そこで、ログメッセージの出力先を rsyslog にした log4j の設定ファイル(my_log4j.properties) を用意し、それを使うようにします。
設定ファイル(my_log4j.properties) の内容は以下のようにします。
log4j.rootLogger=info, SYSLOG
log4j.appender.SYSLOG=org.apache.log4j.net.SyslogAppender
log4j.appender.SYSLOG.syslogHost=localhost
log4j.appender.SYSLOG.layout=org.apache.log4j.PatternLayout
log4j.appender.SYSLOG.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

この設定ファイル(my_log4j.properties)を、JobScheduler が使用するように factory.ini を修正します。
[java]

~省略~

options = -Dlog4j.configuration=file:///home/jobs/sos-berlin.com/jobscheduler/scheduler/config/my_log4j.properties
以上で、設定は完了です。
JobScheduler を再起動すると、/var/log/messages にログが出力されるようになります。
# tail /var/log/messages
Jul 13 08:26:47 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) INFO - Type registration [characters_clob] overrides previous : org.hibernate.type.PrimitiveCharacterArrayClobType@6762ba99#012
Jul 13 08:26:47 localhost  INFO [main] (BasicTypeRegistry.java:150) - Type registration [wrapper_characters_clob] overrides previous : org.hibernate.type.CharacterArrayClobType@2c8c7d6
Jul 13 08:26:47 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) INFO - Type registration [wrapper_characters_clob] overrides previous : org.hibernate.type.CharacterArrayClobType@2c8c7d6#012
Jul 13 08:26:47 localhost  INFO [main] (BasicTypeRegistry.java:150) - Type registration [materialized_clob] overrides previous : org.hibernate.type.MaterializedClobType@4bb7b407
Jul 13 08:26:47 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) INFO - Type registration [materialized_clob] overrides previous : org.hibernate.type.MaterializedClobType@4bb7b407#012
Jul 13 08:26:48 localhost  INFO [main] (SessionFactoryObjectFactory.java:105) - Not binding factory to JNDI, no JNDI name configured
Jul 13 08:26:48 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) INFO - Not binding factory to JNDI, no JNDI name configured#012
Jul 13 08:26:49 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) Job sos/dailyschedule/CheckDaysSchedule terminated.
Jul 13 08:26:49 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) SCHEDULER-918  state=closed
Jul 13 08:26:49 localhost  INFO [main] (CppLogger.scala:19) - (Task sos/dailyschedule/CheckDaysSchedule:4594) SCHEDULER-962  Protocol ends in /home/jobs/sos-berlin.com/jobscheduler/scheduler/logs/task.sos,dailyschedule,CheckDaysSchedule.log

ジョブの実行結果は、以下のように出力されます。(正常終了の場合)
赤字は、ジョブ(shell)の中で、echo したメッセージです。複数行が 1行にまとめて表示されています。
Jul 13 08:32:15 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-892  This Job is going to be replaced due to changed configuration file '/home/jobs/sos-berlin.com/jobscheduler/scheduler/config/live/test/job1.job.xml' (2014-07-13 08:31:57.000+0900)
Jul 13 08:32:15 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-931  state=stopped
Jul 13 08:32:15 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-962  Protocol ends in /home/jobs/sos-berlin.com/jobscheduler/scheduler/logs/job.test,job1.log
Jul 13 08:32:15 localhost  INFO [main] (CppLogger.scala:19) - (Job_folder /test) SCHEDULER-861  'Job test/job1' has been removed
Jul 13 08:32:15 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-893  Job is 'active' now
Jul 13 08:32:25 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-919  Task 4597 enqueued
Jul 13 08:32:25 localhost  INFO [main] (CppLogger.scala:19) - (Job  test/job1) SCHEDULER-930  Task 4597 started - cause: queue_at
Jul 13 08:32:25 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) SCHEDULER-918  state=starting (at=2014-07-13 08:32:25.872+0900)
Jul 13 08:32:25 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) SCHEDULER-987  Starting process: '/bin/sh' '-c' '"/tmp/jobs/sos.sC4Ih0"'
Jul 13 08:32:26 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) job1 processed #012Current Timestamp: 2014-07-13 08:32:26#012Current Hostname: centos65#012Current Username: jobs
Jul 13 08:32:26 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) SCHEDULER-915  Process event
Jul 13 08:32:26 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) SCHEDULER-918  state=closed
Jul 13 08:32:26 localhost  INFO [main] (CppLogger.scala:19) - (Task test/job1:4597) SCHEDULER-962  Protocol ends in /home/jobs/sos-berlin.com/jobscheduler/scheduler/logs/task.test,job1.log


これで JobScheduler のログを rsyslog に出力できました。
せっかくなので、 LogAnalyzer を使って、ブラウザで JobScheduler のログを見てみます。



ジョブの正常終了は以下のように見えます。



ジョブの異常終了は以下のように見えます。



表示がずれているようなので、log4j の設定を以下のように修正してみました。(赤字部分)
ついでに、画面の[syslogtag]欄 に "jobscheduler" と表示されるようにしています。
log4j.rootLogger=info, SYSLOG
log4j.appender.SYSLOG=org.apache.log4j.net.SyslogAppender
log4j.appender.SYSLOG.syslogHost=localhost
log4j.appender.SYSLOG.layout=org.apache.log4j.PatternLayout
log4j.appender.SYSLOG.layout.ConversionPattern=localhost jobscheduler: %5p [%t] (%F:%L) - %m%n

JobScheduler の再起動後、ジョブを異常させると、以下のように表示されました。