kagamihogeの日記

kagamihogeの日記です。

Spring BatchのCommandLineJobRunnerで任意の終了ステータスを返す

背景

たとえば、Spring BatchをCommandLineJobRunnerを使用するjavaコマンドで起動し、そのjavaプロセスの終了ステータスをシェルスクリプトで取得して何らかの条件分岐を行いたい、とする。基本的には、Spring Batchはその終了状態に応じて0,1,2を返すのでこれで十分なのだが、それ以外の任意の値を返したい場合がある。

ソースコードなど

環境

  • spring-batch 3.0.7.RELEASE

JVM終了時に呼ばれるSystemExiter

CommandLineJobRunnerはJVM呼び出し時の拡張ポイントとしてpresetSystemExiterを用意しているので、ここで自前のSystemExiterを設定できる。

import org.springframework.batch.core.launch.support.CommandLineJobRunner;
import org.springframework.batch.core.launch.support.SystemExiter;

...
    public static void main(String[] args) throws Exception {
        CommandLineJobRunner.presetSystemExiter(new SystemExiter() {
            public void exit(int status) {
                System.exit(status);
            }
        });
        CommandLineJobRunner.main(args);
    }

ちなみにEclipseで終了ステータスを確認するにはdebugビューで見れる。

f:id:kagamihoge:20170625183723j:plain

afterJobでExitStausのexitCodeを指定してExitCodeMapperで変換

上のコードは固定値だが、exitメソッドのstatusは基本的にはExitStatusの値が入ってくる。ただし、CommandLineJobRunnerデフォルト動作のSimpleJvmExitCodeMapperが0,1,2のいずれかにExitStatusの値を変換する。そのため、それ以外の値にしたければ自前のExitCodeMapperを設定してやる必要がある。

まず、適当な終了ステータスのExitStatusを返すJobExecutionListenerを作る。リスナ設定のXMLなどについては省略。

import org.springframework.batch.core.ExitStatus;
import org.springframework.batch.core.JobExecution;
import org.springframework.batch.core.JobExecutionListener;

public class JobListener implements JobExecutionListener {

    @Override
    public void beforeJob(JobExecution jobExecution) {
    }

    @Override
    public void afterJob(JobExecution jobExecution) {
        jobExecution.setExitStatus(new ExitStatus("114"));
    }

}

自前のExitCodeMapperを作る。ここでは、単にExitStatusのexitCode文字列をintに変換するだけ。上記のJobListener#afterJobでexitCodeに114の文字列を指定しているので、以下のメソッドはintの114を返す。

import org.springframework.batch.core.launch.support.SimpleJvmExitCodeMapper;

public class CustomExitCodeMapper extends SimpleJvmExitCodeMapper {
    @Override
    public int intValue(String exitCode) {        
        return Integer.parseInt(exitCode);
    }
}

次に、CommandLineJobRunnerにsetExitCodeMapperがあるので、これを使用してセッターインジェクションで、上で作成した自前のCustomExitCodeMapperを設定する。方法は色々あるが、たとえばXMLなら以下のようにする。

<bean id="exitCodeMapper" class="kagamihoge.springbatchexitcode.CustomExitCodeMapper" />

ここの仕組みについては、CommandLineJobRunnerは起動時に引数に与えられたxmlをスキャンし、それを自身にも適用している。なので、たとえばsetExitCodeMapperに対応するexitCodeMapperというidのbeanがあればそれをインジェクションする。

最後に、最初に作成したSystemExiterのところを引数の値をそのままSystem.exitの引数に渡すように変更する。

       CommandLineJobRunner.presetSystemExiter(new SystemExiter() {
            public void exit(int status) {
                System.exit(status);
            }
        });

これで、afterJobで何らかの条件分岐を行い、それを基に任意の終了ステータスを返すことが出来る。

参考URL

WildFly 10でLogback使おうとして挫折した話

まとめ

WildFly 10でLogback使うやり方がわからなかったのと、ログの要件がそんなにきつくなかったのでPer-deployment Loggingを使うことにした。

やったこと

pom.xmlLogbackの依存性を追加する。

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.3</version>
</dependency>

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.25</version>
</dependency>

main/resources/logback.xmlを適当に作成する。

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>logback - %d{HH:mm:ss.SSS} %-5level %logger{10} %msg%n</pattern>
    </encoder>
  </appender>

  <root level="TRACE">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

適当なテスト用のcontrollerをspring-mvcで作っておく。

@RestController
public class HogeController {
    private Logger logger = LoggerFactory.getLogger(HogeController.class);
    
    @RequestMapping("/i")
    public String index() {
        logger.debug("debug");
        logger.info("info");
        logger.error("error");
        
        return "hoge";
    }
}

この段階ではまだlogbackでのログ出力はできない。

jboss - Override logging in WildFly - Stack Overflowlogging - WIldfly 10 + logback - Stack Overflow にあるように、WebContent/META-INF/jboss-deployment-structure.xml を作成する。wildfly側のloggingのsubsytemをdisableにする必要がある、とのこと。

<jboss-deployment-structure>
  <deployment>
     <!-- exclude-subsystem prevents a subsystems deployment unit processors running on a deployment -->
     <!-- which gives basically the same effect as removing the subsystem, but it only affects single deployment -->
     <exclude-subsystems>
        <subsystem name="logging" />
    </exclude-subsystems>
  </deployment>
</jboss-deployment-structure>

しかしEclipse上のコンソールログがちょっとおかしい。

22:27:27,264 INFO  [stdout] (default task-2) logback - 22:27:27.262 DEBUG k.w.c.HogeController debug

22:27:27,265 INFO  [stdout] (default task-2) logback - 22:27:27.265 INFO  k.w.c.HogeController info

22:27:27,265 INFO  [stdout] (default task-2) logback - 22:27:27.265 ERROR k.w.c.HogeController error

こんな感じに余計な改行が一つ入ってしまっている。

java - Wildfly and logback with blank lines - Stack Overflow と、これを読む限り、wildflySystem.outをラップするために改行がいっこ余計に入る、ということらしい。

じゃあってんで、logback.xmlから改行を取り除くとフラッシュが起きなくなるからかログが出なくなる。<immediateFlush>false</immediateFlush>も意味なし(デフォルトtrueだし)

というわけでstandalone.xmlのフォーマットから改行を取り除いてみる。

            <formatter name="COLOR-PATTERN">
                <pattern-formatter pattern="%K{level}%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e"/>
            </formatter>

これでログに余計な改行が無くなるが、今度はwildflyのログの一部(COLOR-PATTERNを使うものと思うが)が改行されなくなる。

logbackが出力するコンソールやファイルへのログは正常に出るんでこれで妥協できなくもないが…

そこでちょっと待てよとlogback.xmlのpatternの末尾を%nではなく\nに変えてみる。

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>logback - %d{HH:mm:ss.SSS} %-5level %logger{10} %msg\n</pattern>
    </encoder>
  </appender>
22:51:45,733 INFO  [stdout] (default task-2) logback - 22:51:45.730 DEBUG k.w.c.HogeController debug
22:51:45,734 INFO  [stdout] (default task-2) logback - 22:51:45.733 INFO  k.w.c.HogeController info
22:51:45,734 INFO  [stdout] (default task-2) logback - 22:51:45.734 ERROR k.w.c.HogeController error

余計な改行が無くなった。ただしwindowsでしか動かしてないので、プラットフォームや環境が変わると動くかどうかはわからない。つまり場当たり的対処でしかない……

そういうわけで。WildFlyのPer-deployment Logging使っておけば良いのでは? という結論になった。この機能はlog4j.xmlとか特定の名前のログ設定ファイルをwarなどに含めておくと、その設定ファイルを使用してwildflyがログ出力してくれるもの。ロギングのライブラリの依存性をwarに含める必要が無く、基本的にはslf4j-apiをprovidedで入れるだけ。

ログの要件的にはこれで十分だったんで、まぁいっかとこれで妥協することにした。

WildFly 10のドキュメントのLogging Configurationを読んだ

https://docs.jboss.org/author/display/WFLY10/Logging+Configuration を読んだ。

WildFly 10が持ってるログのとこ良く分からんなーという感じだったので読んだ。

Logging Configuration

Overview

全体的なサーバのログ設定はlogging subsytemで指定します。logging subsytemは4つの構成要素があり、handler, logger, root logger(ログカテゴリ), profileがあります。loggerはhandler(もしくはその組み合わせ)を参照します。hadlerはログフォーマットと出力を宣言します。

<subsystem xmlns="urn:jboss:domain:logging:3.0">
   <console-handler name="CONSOLE" autoflush="true">
       <level name="DEBUG"/>
       <formatter>
           <named-formatter name="COLOR-PATTERN"/>
       </formatter>
   </console-handler>
   <periodic-rotating-file-handler name="FILE" autoflush="true">
       <formatter>
           <named-formatter name="PATTERN"/>
       </formatter>
       <file relative-to="jboss.server.log.dir" path="server.log"/>
       <suffix value=".yyyy-MM-dd"/>
   </periodic-rotating-file-handler>
   <logger category="com.arjuna">
       <level name="WARN"/>
   </logger>
   [...]
   <root-logger>
       <level name="DEBUG"/>
       <handlers>
           <handler name="CONSOLE"/>
           <handler name="FILE"/>
       </handlers>
   </root-logger>
   <formatter name="PATTERN">
       <pattern-formatter pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
   </formatter>
   <formatter name="COLOR-PATTERN">
       <pattern-formatter pattern="%K{level}%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
   </formatter>
</subsystem>

Attributes

ルート要素には二つの属性add-logging-api-dependenciesuse-deployment-logging-configがあります。

add-logging-api-dependencies

add-logging-api-dependenciesはデプロイ対象物に暗黙的なロギングAPIの依存性をコンテナが追加するかどうかを制御します。デフォルトのtrueの場合はすべての暗黙的なロギングAPIの依存性が追加されます。falseの場合は追加されません。

use-deployment-logging-config

use-deployment-logging-configはデプロイ対象物がper-deployment loggingのスキャン対象にするかどうかを制御します。デフォルトのtrueの場合はper-deployment loggingは有効化されます。falseの場合は無効化されます。

Per-deployment Logging

Per-deployment loggingを使うと、デプロイ対象物にログ設定ファイルを追加するとその設定ファイルに従ったロギングが行われます。EARでは設定ファイルはMETA-INFディレクトリに配置します。WARやJARではMETA-INFWEB-INF/classesに置きます。

以下の設定ファイルが使用可能です。

なおuse-deployment-logging-config属性をfalseに変更することでこの機能を無効化できます。

Logging Profiles

Logging profilesはlogging subsystemsを追加する感じのものです。個々のLogging profilesは上述の四要素のうちhandler, logger, root loggerの三つで構成されます。

デプロイ対象物にはmanifest経由でlogging profileを割り当てられます。MANIFEST.MFファイルにLogging-Profileエントリを追加してその値にlogging profileのidを指定します。/subsystem=logging/logging-profile=ejbsで定義したlogging profileはMANIFEST.MFで以下のように指定します。

Manifest-Version: 1.0
Logging-Profile: ejbs

logging profileは複数のデプロイ対象物で指定可能です。また、logging profileを使うことで実行時に設定を変更可能になります。これはper-deployment loggingにはない利点で、ログ設定の変更を反映するのに再デプロイが不要です。

Default Log File Locations

Managed Domain

managed domainでは二種類のログファイルが存在し、Controllerとserver logsがあります。controllerコンポーネントは全体的なドメインを管理します。このコンポーネントはサーバインスタンスのstart/stopとドメイン全体のマネージド操作実行を担当します。Server logsには特定のサーバインスタンスのログ情報が含まれます。これらのログは稼働中のサーバとホストに配置されます。

説明を簡単にするためマネージドドメインのデフォルトのセットアップを見ます。この場合ドメインコントローラーコンポーネントとサーバは両方とも同一ホスト上に存在します。

Process Log File
Host Controller ./domain/log/host-controller.log
Process Controller ./domain/log/process-controller.log
“Server One” ./domain/servers/server-one/log/server.log
“Server Two” ./domain/servers/server-two/log/server.log
“Server Three” ./domain/servers/server-three/log/server.log

Standalone Server

standaloneサーバのデフォルトのログファイルはディストリビューションのlogディレクトリにあります。

Process Log File
Server ./standalone/log/server.log

Filter Expressions

Filter Type Expression Description Parameter(s) Examples
accept accept すべてのログメッセージを許容 なし accept
deny deny すべてのログメッセージを拒否 なし deny
not not(filterExpression) 引数としてフィルタを取りその戻り値を反転 引数に一つのフィルタを取る not(match(“JBAS”))
all all(filterExpressions) チェーンの複数フィルタから成るフィルタ。あるフィルタがunloggableなログメッセージを検出する場合、そのメッセージはログ出力されず、それ以降のフィルタはチェックされません。 引数にフィルタリストのカンマ区切りを取る all(match(“JBAS”), match(“WELD”))
any any(filterExpressions) チェーンの複数フィルタから成るフィルタ。あるフィルタがログ出力可能なメッセージを検出する場合、そのメッセージはログ出力され、それ以降のフィルタはチェックされません。 引数にフィルタリストのカンマ区切りを取る any(match(“JBAS”), match(“WELD”))
levelChange levelChange(level) ログレコードを別のレベルに変更するフィルタ 引数にレベルの文字列を一つ取る levelChange(WARN)
levels levels(levels) リストで示すレベルのログメッセージを含むフィルタ。 引数にレベルのカンマ区切りのリストを取る levels(DEBUG, INFO, WARN, ERROR)
levelRange levelRange([minLevel,maxLevel]) あるレベル範囲内のログを出力するフィルタ 最小レベルを"[“、最大レベルを”]“で示すフィルター式です。反対に”(“と”)“はそのレベルを含みません。式の最初の引数が最小レベルで、二つ目が最大レベルです。 最小レベルはERROR未満で最大レベルはDEBUGより大きい。

levelRange(ERROR, DEBUG)

最小レベルはERROR以下で最大レベルはDEBUGより大きい。

levelRange[ERROR, DEBUG)

最小レベルはERROR以下で最大レベルはINFO以上。

levelRange[ERROR, INFO]
match match(“pattern”) 正規表現ベースのフィルタ。パターンマッチには未フォーマットの生メッセージが使われます。 この式は引数に正規表現を取る。 match(“JBAS\d+”)
substitute substitute(“pattern”, “replacement value”) パターンに最初にマッチする箇所をreplacementの値で置換するフィルタ。 最初の引数がパターンで次が置換するテキスト substitute(“JBAS”, “EAP”)
substituteAll substituteAll(“pattern”, “replacement value”) パターンにマッチするすべての箇所をreplacementの値で置換するフィルタ。 最初の引数がパターンで次が置換するテキスト substituteAll(“JBAS”, “EAP”)

List Log Files and Reading Log Files

ログファイルは管理操作で参照や一覧表示ができます。参照可能なログファイルは意図的に制限されており、jboss.server.log.dirに存在するファイルで既知のファイルハンドラを関連付けているファイルに限られます。既知のファイルハンドラの種類はfile-handler, periodic-rotating-file-handle, size-rotating-file-handlerです。管理操作はstandaloneとdomainモードの両方で有効です。

List Log Files

logging subsystemにはログファイルを一覧表示するlog-fileがあります。これにはsubsystem rootのリソースとlogging-profileのリソースは含みません。*1

CLI command and output

[standalone@localhost:9990 /] /subsystem=logging:read-children-names(child-type=log-file)
{
    "outcome" => "success",
    "result" => [
        "server.log",
        "server.log.2014-02-12",
        "server.log.2014-02-13"
    ]
}

Read Log File

read-log-fileオペレーションはlog-fileリソースに対して使用可能です。このオペレーションには4つのオプションパラメータがあります。

Name Description
encoding 読み込むファイルのエンコーディング
lines ファイルの行数。-1はすべて読み込む
skip 読み込む前にスキップする行数
tail trueでファイルの終端から、falseで開始から読み込む

CLI command and output

[standalone@localhost:9990 /] /subsystem=logging/log-file=server.log:read-log-file
{
    "outcome" => "success",
    "result" => [
        "2014-02-14 14:16:48,781 INFO  [org.jboss.as.server.deployment.scanner] (MSC service thread 1-11) JBAS015012: Started FileSystemDeploymentService for directory /home/jperkins/servers/wildfly-8.0.0.Final/standalone/deployments",
        "2014-02-14 14:16:48,782 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-8) JBAS010400: Bound data source [java:jboss/myDs]",
        "2014-02-14 14:16:48,782 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-15) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS]",
        "2014-02-14 14:16:48,786 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-9) JBAS015876: Starting deployment of \"simple-servlet.war\" (runtime-name: \"simple-servlet.war\")",
        "2014-02-14 14:16:48,978 INFO  [org.jboss.ws.common.management] (MSC service thread 1-10) JBWS022052: Starting JBoss Web Services - Stack CXF Server 4.2.3.Final",
        "2014-02-14 14:16:49,160 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-16) JBAS017534: Registered web context: /simple-servlet",
        "2014-02-14 14:16:49,189 INFO  [org.jboss.as.server] (Controller Boot Thread) JBAS018559: Deployed \"simple-servlet.war\" (runtime-name : \"simple-servlet.war\")",
        "2014-02-14 14:16:49,224 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9990/management",
        "2014-02-14 14:16:49,224 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9990",
        "2014-02-14 14:16:49,225 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: WildFly 8.0.0.Final \"WildFly\" started in 1906ms - Started 258 of 312 services (90 services are lazy, passive or on-demand)"
    ]
}

FAQ

Why is there a logging.properties file?

configurationディレクトリのlogging.propertiesの存在をご存知かもしれません。サーバ起動時にlogging subsystemが開始するまではこれがロギングの設定になります。もしlogging subsystemを設定で含めない場合、このファイルがサーバ全体のロギング設定として振る舞います。

logging.propertiesファイルはブート時に上書きされ、変更箇所はlogging subsystemに反映されます。ファイルに加えられた変更は永続化されません。XML configurationもしくは管理操作で加えられた変更はlogging.propertiesに永続化されて次回のブート時に使用されます。

*1:The logging subsystem has a log-file resource off the subsystem root resource and off each logging-profile resource to list each log file. が原文。二回出てくるoffのあたりがちょっと訳に自信が無い。