Kohei Nozaki's blog 

ExitStatusでフロー制御してみる


Posted on Sunday Feb 16, 2014 at 08:17AM in Technology


ExitStatusでフロー制御的なことをして遊んでみる

環境・前提条件

仕様を見てみる

[1]から引いてみる

8.6 Transition Elements

Transition elements may be specified in the containment scope of a step, flow, split, or decision to direct job execution sequence or to terminate job execution. There are four transition elements:

  1. next - directs execution flow to the next execution element.
  2. fail - causes a job to end with FAILED batch status.
  3. end - causes a job to end with COMPLETED batch status.
  4. stop - causes a job to end with STOPPED batch status.

Fail end, and stop are considered “terminating elements” because they cause a job execution to terminate.

この4つを使って遊んでみる

サンプルの仕様

  • 第一レベルの要素は以下
    1. step1
    2. step2
  • どちらも参照するartifactは同じExitStatusBatchlet
    • パラメータで与えたExitStatusで終わるだけ
    • step1のExitStatusはジョブパラメータで変えられるようにしてある
    • step2のExitStatusはnull(COMPLETED)固定
  • step1には先で引いたTransition Elementsを4つ指定してある
  • 4つのテストメソッドでstep1のExitStatusを以下のパターンで変えてテストする
    • next(): step2に遷移する
    • fail(): step1で異常終了
    • end(): step1で正常終了
    • stop(): step1で停止

資源

資源はこのへんにまとめて全部ある

動かしてみる

next

ログ

10:29:46,990 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 6) step1: exitStatus=NEXT
10:29:47,009 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 6) step2: exitStatus=null

Repository

job_execution
jbatch=# select * from job_execution order by jobexecutionid desc limit 1;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus | exitstatus |   jobparameters   | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+-------------------+-----------------
            148 |           141 |         | 2014-02-16 10:29:46.976 | 2014-02-16 10:29:46.976 | 2014-02-16 10:29:47.011 | 2014-02-16 10:29:47.011 | COMPLETED   | COMPLETED  | exitStatus = NEXT+| 
                |               |         |                         |                         |                         |                         |             |            |                   | 
(1 row)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (148) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |        starttime        |         endtime         | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             171 |            148 |         | step1    | 2014-02-16 10:29:46.982 | 2014-02-16 10:29:46.991 | COMPLETED   | NEXT       |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
             172 |            148 |         | step2    | 2014-02-16 10:29:47.008 | 2014-02-16 10:29:47.009 | COMPLETED   | COMPLETED  |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(2 rows)
  • 普通にstep2に遷移している

fail

ログ

10:41:31,341 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 9) step1: exitStatus=FAIL

Repository

job_execution
jbatch=# select * from job_execution order by jobexecutionid desc limit 1;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus |        exitstatus         |   jobparameters   | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+---------------------------+-------------------+-----------------
            149 |           142 |         | 2014-02-16 10:41:31.338 | 2014-02-16 10:41:31.338 | 2014-02-16 10:41:31.344 | 2014-02-16 10:41:31.344 | FAILED      | EARLY COMPLETION (FAILED) | exitStatus = FAIL+| 
                |               |         |                         |                         |                         |                         |             |                           |                   | 
(1 row)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (149) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |        starttime        |         endtime         | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             173 |            149 |         | step1    | 2014-02-16 10:41:31.339 | 2014-02-16 10:41:31.341 | COMPLETED   | FAIL       |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(1 row)
  • step1終了後に異常終了している
  • step_executionのbatchstatusがCOMPLETEDなのが気になるけどjob_executionのbatchstatusはちゃんとFAILEDになっている

end

ログ

10:43:54,134 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 3) step1: exitStatus=END

Repository

job_execution
jbatch=# select * from job_execution order by jobexecutionid desc limit 1;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus |       exitstatus       |  jobparameters   | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------------------+------------------+-----------------
            150 |           143 |         | 2014-02-16 10:43:54.129 | 2014-02-16 10:43:54.129 | 2014-02-16 10:43:54.137 | 2014-02-16 10:43:54.137 | COMPLETED   | EARLY COMPLETION (END) | exitStatus = END+| 
                |               |         |                         |                         |                         |                         |             |                        |                  | 
(1 row)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (150) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |       starttime        |         endtime         | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             174 |            150 |         | step1    | 2014-02-16 10:43:54.13 | 2014-02-16 10:43:54.134 | COMPLETED   | END        |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(1 row)
  • step2には遷移せず正常終了している

stop

ログ

10:46:52,718 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 2) step1: exitStatus=STOP

Repository

job_execution
jbatch=# select * from job_execution order by jobexecutionid desc limit 1;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |        endtime         |    lastupdatedtime     | batchstatus |       exitstatus        |   jobparameters   | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+------------------------+------------------------+-------------+-------------------------+-------------------+-----------------
            151 |           144 |         | 2014-02-16 10:46:52.705 | 2014-02-16 10:46:52.705 | 2014-02-16 10:46:52.72 | 2014-02-16 10:46:52.72 | STOPPED     | EARLY COMPLETION (STOP) | exitStatus = STOP+| step2
                |               |         |                         |                         |                        |                        |             |                         |                   | 
(1 row)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (151) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |        starttime        |         endtime         | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             175 |            151 |         | step1    | 2014-02-16 10:46:52.712 | 2014-02-16 10:46:52.718 | COMPLETED   | STOP       |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(1 row)
  • step1終了後に停止している
  • step_executionのbatchstatusがCOMPLETEDなのが気になるけどjob_executionのbatchstatusはちゃんとSTOPPEDになっている

stop要素のrestart属性で再実行時に遷移するstepを指定してみる

仕様を引いてみる

[1]の「8.6.4 Stop Element」に、restart属性についてこう書いてある

Specifies the job-level step, flow, or split at which to restart when the job is restarted. It must be a valid XML string value. This is a required attribute.

再実行してみる

テストメソッドstopRestart()に再実行のテストを書いてあるので実行してみる

ログ

10:58:59,039 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 4) step1: exitStatus=STOP
10:59:00,053 WARN  [org.jberet] (batch-batch - 6) JBERET000018: Could not find the original step execution to restart.  Current step execution id: 0, step name: step2
10:59:00,054 FINE  [org.nailedtothex.jbatch.example.on.ExitStatusBatchlet] (batch-batch - 6) step2: exitStatus=null

Repository

job_execution
jbatch=# select * from job_execution where jobexecutionid in (161, 162) order by jobexecutionid;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus |       exitstatus        |   jobparameters   | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+-------------------------+-------------------+-----------------
            161 |           151 |         | 2014-02-16 10:58:59.035 | 2014-02-16 10:58:59.035 | 2014-02-16 10:58:59.042 | 2014-02-16 10:58:59.042 | STOPPED     | EARLY COMPLETION (STOP) | exitStatus = STOP+| step2
                |               |         |                         |                         |                         |                         |             |                         |                   | 
            162 |           151 |         | 2014-02-16 10:59:00.05  | 2014-02-16 10:59:00.05  | 2014-02-16 10:59:00.056 | 2014-02-16 10:59:00.056 | COMPLETED   | COMPLETED               | exitStatus = STOP+| 
                |               |         |                         |                         |                         |                         |             |                         |                   | 
(2 rows)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (161, 162) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |        starttime        |         endtime         | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             186 |            161 |         | step1    | 2014-02-16 10:58:59.037 | 2014-02-16 10:58:59.04  | COMPLETED   | STOP       |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
             187 |            162 |         | step2    | 2014-02-16 10:59:00.051 | 2014-02-16 10:59:00.054 | COMPLETED   | COMPLETED  |                    |                    |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(2 rows)
  • 一応予想通り動いたけど、ログにWARNで出ている文言が気になる
  • 再実行時に初回実行時に実行してないStepから再開するっていうのは仕様上微妙なのかも

備考

  • on属性にはワイルドカード(*と?)が使える
  • next on=“*” とかよく使いそう
  • endは正常系で後続処理やらなくて良い時に使う感じ。非営業日だから何もせずに終わりとか(営業日関連はジョブ内でやらずに、ジョブ呼び出すところを作り込んでジョブが動く前に止めた方がいい気がするけど)
  • failは異常系の時(例外投げてもいい気がするけど)
  • stopは再実行前提で止めたい時とか、再実行するstepを制御したい時に使う?どういう状況で使うのかいまいち想像できないけど
  • 先行処理の状況から分岐させたいときは、StepExecutionの配列を受け取ってExitStatusを決められるDeciderを使うのが良い

参考文献

  1. JSR-000352 Batch Applications for the Java Platform - Final Release


A way to resolve dependencies of jobs


Posted on Sunday Feb 16, 2014 at 08:17AM in Technology


This is about a way to resolve dependencies of jobs that used only JSR 352 API.

Environment

  • jBeret 1.0.1Beta-SNAPSHOT
  • WildFly 8.0.0.Final

Why need it?

  • For tasks that need to execute sequentially, usually we have to let all tasks in single job XML.
  • I guess it would bring huge difficulty of testing.
    • For example, I don't want to test such big job like EndOfTheDay.xml
  • Rather than I would go with smaller jobs with external job control system.

How realize it?

  • This needs to create parent job XML that defines dependencies of child jobs.
  • Every step uses artifact named “jobLauncherBatchlet”
    • This batchlet invokes child job. name of the job and job parameters are given by its parameter of the step.
    • After invoke the job, then it starts polling BatchStatus, and wait till the job is finished.

Sample project

Whole resources are available in GitHub.

log

13:45:22,589 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step1: persistentUserData=null, waitForFinish=null
13:45:22,589 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step1: starting new job: jobXMLName=jobdependency-child1, properties={sleepInMillis=1000}
13:45:22,593 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step1: job started: executionId=207
13:45:22,593 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step1: waiting for finish the job... executionId=207
13:45:22,595 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 2) entering process(): stepName=child1-step1, sleepInMills=1,000
13:45:23,596 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 2)  exiting process(): stepName=child1-step1, sleepInMills=1,000
13:45:24,595 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step1: job finished: BatchStatus=COMPLETED
13:45:24,601 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step2: persistentUserData=null, waitForFinish=null
13:45:24,601 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step2: starting new job: jobXMLName=jobdependency-child2, properties={sleepInMillis=2000}
13:45:24,605 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step2: job started: executionId=208
13:45:24,605 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step2: waiting for finish the job... executionId=208
13:45:24,606 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 4) entering process(): stepName=child2-step1, sleepInMills=2,000
13:45:26,608 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 4)  exiting process(): stepName=child2-step1, sleepInMills=2,000
13:45:27,608 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step2: job finished: BatchStatus=COMPLETED
13:45:27,614 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step3: persistentUserData=null, waitForFinish=null
13:45:27,614 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step3: starting new job: jobXMLName=jobdependency-child3, properties={sleepInMillis=3000}
13:45:27,618 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step3: job started: executionId=209
13:45:27,618 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step3: waiting for finish the job... executionId=209
13:45:27,619 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 9) entering process(): stepName=child3-step1, sleepInMills=3,000
13:45:30,620 FINE  [org.nailedtothex.jbatch.example.split.SleepBatchlet] (batch-batch - 9)  exiting process(): stepName=child3-step1, sleepInMills=3,000
13:45:31,620 FINE  [org.nailedtothex.jbatch.example.jobdependency.JobLaunchBatchlet] (batch-batch - 8) step3: job finished: BatchStatus=COMPLETED

Job repository tables

job_instance and job_execution

jbatch=# select * from job_instance i, job_execution e where i.jobinstanceid = e.jobinstanceid and i.jobname like 'jobdependency%' and i.jobinstanceid >= 194 order by e.jobexecutionid;
 jobinstanceid | version |       jobname        | applicationname | jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus | exitstatus |    jobparameters     | restartposition 
---------------+---------+----------------------+-----------------+----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+----------------------+-----------------
           194 |         | jobdependency        | jbatchtest      |            206 |           194 |         | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:31.623 | 2014-02-19 13:45:31.623 | COMPLETED   | COMPLETED  |                      | 
           195 |         | jobdependency-child1 | jbatchtest      |            207 |           195 |         | 2014-02-19 13:45:22.592 | 2014-02-19 13:45:22.592 | 2014-02-19 13:45:23.599 | 2014-02-19 13:45:23.599 | COMPLETED   | COMPLETED  | sleepInMillis = 1000+| 
               |         |                      |                 |                |               |         |                         |                         |                         |                         |             |            |                      | 
           196 |         | jobdependency-child2 | jbatchtest      |            208 |           196 |         | 2014-02-19 13:45:24.604 | 2014-02-19 13:45:24.604 | 2014-02-19 13:45:26.611 | 2014-02-19 13:45:26.611 | COMPLETED   | COMPLETED  | sleepInMillis = 2000+| 
               |         |                      |                 |                |               |         |                         |                         |                         |                         |             |            |                      | 
           197 |         | jobdependency-child3 | jbatchtest      |            209 |           197 |         | 2014-02-19 13:45:27.617 | 2014-02-19 13:45:27.617 | 2014-02-19 13:45:30.624 | 2014-02-19 13:45:30.624 | COMPLETED   | COMPLETED  | sleepInMillis = 3000+| 
               |         |                      |                 |                |               |         |                         |                         |                         |                         |             |            |                      | 
(4 rows)

step_execution

jbatch=# select * from step_execution s, job_execution e, job_instance i where s.jobexecutionid = e.jobexecutionid and e.jobinstanceid = i.jobinstanceid and i.jobinstanceid >= 194 order by s.starttime;
 stepexecutionid | jobexecutionid | version |   stepname   |        starttime        |         endtime         | batchstatus | exitstatus | executionexception |                                                                           persistentuserdata                                                                           | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo | jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus | exitstatus |    jobparameters     | restartposition | jobinstanceid | version |       jobname        | applicationname 
-----------------+----------------+---------+--------------+-------------------------+-------------------------+-------------+------------+--------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------+----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+----------------------+-----------------+---------------+---------+----------------------+-----------------
             277 |            206 |         | step1        | 2014-02-19 13:45:22.587 | 2014-02-19 13:45:24.595 | COMPLETED   | COMPLETED  |                    | \xaced00057372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b020000787000000000000000cf |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            206 |           194 |         | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:31.623 | 2014-02-19 13:45:31.623 | COMPLETED   | COMPLETED  |                      |                 |           194 |         | jobdependency        | jbatchtest
             278 |            207 |         | child1-step1 | 2014-02-19 13:45:22.593 | 2014-02-19 13:45:23.596 | COMPLETED   | SUCCESS    |                    |                                                                                                                                                                        |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            207 |           195 |         | 2014-02-19 13:45:22.592 | 2014-02-19 13:45:22.592 | 2014-02-19 13:45:23.599 | 2014-02-19 13:45:23.599 | COMPLETED   | COMPLETED  | sleepInMillis = 1000+|                 |           195 |         | jobdependency-child1 | jbatchtest
                 |                |         |              |                         |                         |             |            |                    |                                                                                                                                                                        |           |            |             |               |               |                  |             |                |                      |                      |                |               |         |                         |                         |                         |                         |             |            |                      |                 |               |         |                      | 
             279 |            206 |         | step2        | 2014-02-19 13:45:24.599 | 2014-02-19 13:45:27.608 | COMPLETED   | COMPLETED  |                    | \xaced00057372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b020000787000000000000000d0 |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            206 |           194 |         | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:31.623 | 2014-02-19 13:45:31.623 | COMPLETED   | COMPLETED  |                      |                 |           194 |         | jobdependency        | jbatchtest
             280 |            208 |         | child2-step1 | 2014-02-19 13:45:24.605 | 2014-02-19 13:45:26.608 | COMPLETED   | SUCCESS    |                    |                                                                                                                                                                        |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            208 |           196 |         | 2014-02-19 13:45:24.604 | 2014-02-19 13:45:24.604 | 2014-02-19 13:45:26.611 | 2014-02-19 13:45:26.611 | COMPLETED   | COMPLETED  | sleepInMillis = 2000+|                 |           196 |         | jobdependency-child2 | jbatchtest
                 |                |         |              |                         |                         |             |            |                    |                                                                                                                                                                        |           |            |             |               |               |                  |             |                |                      |                      |                |               |         |                         |                         |                         |                         |             |            |                      |                 |               |         |                      | 
             281 |            206 |         | step3        | 2014-02-19 13:45:27.612 | 2014-02-19 13:45:31.621 | COMPLETED   | COMPLETED  |                    | \xaced00057372000e6a6176612e6c616e672e4c6f6e673b8be490cc8f23df0200014a000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b020000787000000000000000d1 |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            206 |           194 |         | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:22.586 | 2014-02-19 13:45:31.623 | 2014-02-19 13:45:31.623 | COMPLETED   | COMPLETED  |                      |                 |           194 |         | jobdependency        | jbatchtest
             282 |            209 |         | child3-step1 | 2014-02-19 13:45:27.618 | 2014-02-19 13:45:30.62  | COMPLETED   | SUCCESS    |                    |                                                                                                                                                                        |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      |                      |            209 |           197 |         | 2014-02-19 13:45:27.617 | 2014-02-19 13:45:27.617 | 2014-02-19 13:45:30.624 | 2014-02-19 13:45:30.624 | COMPLETED   | COMPLETED  | sleepInMillis = 3000+|                 |           197 |         | jobdependency-child3 | jbatchtest
                 |                |         |              |                         |                         |             |            |                    |                                                                                                                                                                        |           |            |             |               |               |                  |             |                |                      |                      |                |               |         |                         |                         |                         |                         |             |            |                      |                 |               |         |                      | 
(6 rows)
  • We can see that they were executed in particular order.

Remarks

  • I intent to care of stop and restart, and sample project contains some codes about it, but I haven't tested it yet. maybe I would write about it too later.
  • It can use some functions of jobXML such as parallel executions (like split element) for control of job execution even.

Take care of the max number of threads in thread-pool

  • Some implementations have limit of threads count.
  • When you used this method or similar one with many parallel execution elements (split or partition), you must ensure to keep number of threads lower than the limit.
  • If limit reaches, your batch will be frozen and it won't resume.

How to configure max threads

  • On WildFly + jBeret, the max number of threads is set to 10 as default.
  • This increases the limit to 100:
/subsystem=batch/thread-pool=batch:write-attribute(name=max-threads, value=100)


StepContext#persistentUserDataで遊ぶ


Posted on Sunday Feb 16, 2014 at 07:43AM in Technology


StepContext#persistentUserDataにはStepに紐づくデータを保存しておける。ここに入れたデータはJobRepositoryに保存され、後続のStepやジョブの再実行時に参照できる。何かしら使い道があると思われるので若干遊んでみる

環境・前提条件

関連メソッドの仕様を見てみる

[1]から引いてみる

javax.batch.runtime.context.StepContextインタフェース

Stepに関連する操作をする時に使うインタフェース。artifactで@Injectで注入して使える。

    /**
     * The getPersistentUserData method returns a persistent data object 
     * belonging to the current step. The user data type must implement 
     * java.util.Serializable. This data is saved as part of a step's 
     * checkpoint. For a step that does not do checkpoints, it is saved 
     * after the step ends. It is available upon restart. 
     * @return user-specified type
     */
    public Serializable getPersistentUserData();

    /**
     * The setPersistentUserData method stores a persistent data object 
     * into the current step. The user data type must implement 
     * java.util.Serializable. This data is saved as part of a step's 
     * checkpoint. For a step that does not do checkpoints, it is saved 
     * after the step ends. It is available upon restart. 
     * @param data is the user-specified type
     */ 
    public void setPersistentUserData(Serializable data);

javax.batch.runtime.StepExecutionインタフェース

Stepの実行履歴的な情報を含むインタフェース。JobOperatorを使って引っ張って来れたり、Deciderのメソッドの引数で受け取れたりする。

    /**
     * Get user persistent data
     * @return persistent data 
     */
    public Serializable getPersistentUserData();

先行StepでセットしたpersistentUserDataを後続Stepで参照してみる

サンプルの仕様

  • 第一レベルの要素は動作順に以下
    1. set (setPersistentUserDataBatchlet)
    2. get (getPersistentUserDataBatchlet)
  • setでセットしたpersistentUserDataをgetで参照してみる

資源

資源はこのへんにまとめて全部ある

動かしてみる

ログ

08:52:02,642 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.SetPersistentUserDataBatchlet] (batch-batch - 4) set: process()
08:52:02,649 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetPersistentUserDataBatchlet] (batch-batch - 4) get: process()
08:52:02,650 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetPersistentUserDataBatchlet] (batch-batch - 4) stepExecution: stepName=set, persistentUserData=* my step name is set *
08:52:02,650 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetPersistentUserDataBatchlet] (batch-batch - 4) stepExecution: stepName=get, persistentUserData=null

setステップで設定した「 my step name is set 」がgetステップから見えている(3行目)。うむ

Repository

job_execution
jbatch=# select * from job_execution order by jobexecutionid desc limit 1;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus | exitstatus | jobparameters | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+---------------+-----------------
            131 |           126 |         | 2014-02-16 08:52:02.637 | 2014-02-16 08:52:02.637 | 2014-02-16 08:52:02.653 | 2014-02-16 08:52:02.653 | COMPLETED   | COMPLETED  |               | 
(1 row)
step_execution
jbatch=# select * from step_execution where jobexecutionid = 131 order by stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname |        starttime        |         endtime         | batchstatus | exitstatus | executionexception |                       persistentuserdata                       | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+----------------------------------------------------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             153 |            131 |         | set      | 2014-02-16 08:52:02.639 | 2014-02-16 08:52:02.642 | COMPLETED   | COMPLETED  |                    | \xaced00057400172a206d792073746570206e616d6520697320736574202a |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
             154 |            131 |         | get      | 2014-02-16 08:52:02.645 | 2014-02-16 08:52:02.65  | COMPLETED   | COMPLETED  |                    |                                                                |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(2 rows)

persistentuserdataカラムに何かが入っている。うむ

前回実行時のデータを再実行時に参照してみる

サンプルの仕様

  • Stepは1つだけ
  • 何もpersistentUserDataに入ってなかったら
    1. persistentUserDataにデータを入れる
    2. 例外投げて死ぬ
  • 何かpersistentUserDataに入っていたら
    1. 内容を表示して終了
  • 初回実行はpersistentUserDataにデータ入れてFAILEDになる
  • 再実行時はpersistentUserDataのデータを表示してCOMPLETEDになる

資源

資源はこのへんにまとめて全部ある

動かしてみる

ログ

09:15:07,338 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetAndSetPersistentUserDataBatchlet] (batch-batch - 3) getAndSet: process()
09:15:07,339 WARN  [org.jberet] (batch-batch - 3) JBERET000001: Failed to run batchlet org.jberet.job.model.RefArtifact@7e76d151: java.lang.RuntimeException: to confirm whether the data is visible or not when restart
    at org.nailedtothex.jbatch.example.persistentuserdata.GetAndSetPersistentUserDataBatchlet.process(GetAndSetPersistentUserDataBatchlet.java:31) [classes:]
    at org.jberet.runtime.runner.BatchletRunner.run(BatchletRunner.java:61) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:207) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:131) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:162) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:58) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
    at org.wildfly.jberet.services.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:149) [wildfly-jberet-8.0.0.Final.jar:8.0.0.Final]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_51]
    at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_51]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_51]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_51]
    at java.lang.Thread.run(Thread.java:744) [rt.jar:1.7.0_51]
    at org.jboss.threads.JBossThread.run(JBossThread.java:122)

09:15:08,351 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetAndSetPersistentUserDataBatchlet] (batch-batch - 2) getAndSet: process()
09:15:08,351 FINE  [org.nailedtothex.jbatch.example.persistentuserdata.GetAndSetPersistentUserDataBatchlet] (batch-batch - 2) persistentUserData=* my job execution id is 134 *

初回実行時に入れた「 my job execution id is 134 」が再実行時に見えている。うむ

Repository

job_execution
jbatch=# select * from job_execution where jobexecutionid in (134, 135) order by jobexecutionid;
 jobexecutionid | jobinstanceid | version |       createtime        |        starttime        |         endtime         |     lastupdatedtime     | batchstatus | exitstatus | jobparameters | restartposition 
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+---------------+-----------------
            134 |           128 |         | 2014-02-16 09:15:07.335 | 2014-02-16 09:15:07.335 | 2014-02-16 09:15:07.343 | 2014-02-16 09:15:07.343 | FAILED      | FAILED     |               | 
            135 |           128 |         | 2014-02-16 09:15:08.347 | 2014-02-16 09:15:08.347 | 2014-02-16 09:15:08.354 | 2014-02-16 09:15:08.354 | COMPLETED   | COMPLETED  |               | 
(2 rows)
step_execution
jbatch=# select * from step_execution where jobexecutionid in (134, 135) order by jobexecutionid, stepexecutionid;
 stepexecutionid | jobexecutionid | version | stepname  |        starttime        |         endtime         | batchstatus | exitstatus |                                                                   executionexception                                                                   |                              persistentuserdata                              | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo 
-----------------+----------------+---------+-----------+-------------------------+-------------------------+-------------+------------+--------------------------------------------------------------------------------------------------------------------------------------------------------+------------------------------------------------------------------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------+----------------------
             157 |            134 |         | getAndSet | 2014-02-16 09:15:07.336 | 2014-02-16 09:15:07.34  | FAILED      | FAILED     | java.lang.RuntimeException: to confirm whether the data is visible or not when restart                                                                +| \xaced000574001e2a206d79206a6f6220657865637574696f6e20696420697320313334202a |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
                 |                |         |           |                         |                         |             |            |         at org.nailedtothex.jbatch.example.persistentuserdata.GetAndSetPersistentUserDataBatchlet.process(GetAndSetPersistentUserDataBatchlet.java:31)+|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.BatchletRunner.run(BatchletRunner.java:61)                                                                       +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:207)                                             +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:131)                                                            +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:162)                                              +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88)                             +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:58)                                                               +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.wildfly.jberet.services.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:149)                        +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)                                                                    +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at java.util.concurrent.FutureTask.run(FutureTask.java:262)                                                                                   +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)                                                            +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)                                                            +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at java.lang.Thread.run(Thread.java:744)                                                                                                      +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |         at org.jboss.threads.JBossThread.run(JBossThread.java:122)                                                                                    +|                                                                              |           |            |             |               |               |                  |             |                |                      | 
                 |                |         |           |                         |                         |             |            |                                                                                                                                                        |                                                                              |           |            |             |               |               |                  |             |                |                      | 
             158 |            135 |         | getAndSet | 2014-02-16 09:15:08.349 | 2014-02-16 09:15:08.352 | COMPLETED   | COMPLETED  |                                                                                                                                                        | \xaced000574001e2a206d79206a6f6220657865637574696f6e20696420697320313334202a |         0 |          0 |           0 |             0 |             0 |                0 |           0 |              0 |                      | 
(2 rows)

備考

  • 再実行時にはpersistentUserDataがコピーされるようなので、データ量がでかい場合は気をつけた方がいいのかも

参考文献

  1. JSR-000352 Batch Applications for the Java Platform - Final Release


How to define a JavaMail session using CLI


Posted on Sunday Feb 16, 2014 at 07:30AM in Technology


  • Defining a JavaMail session for gmail.

Environment

  • WildFly8.0.0.Final
  • Oracle JDK7u51

Defining with jboss-cli

Define a outbound-socket-binding named “MyMailSMTP”

  • SMTP server hostname
  • SMTP server port
/socket-binding-group=standard-sockets/remote-destination-outbound-socket-binding=MyMailSMTP:add( \
host=smtp.gmail.com, \
port=465)

Define a JavaMail session named “MyMail”

  • JNDI name of JavaMail session
  • Email address of the sender
  • Debug flag
/subsystem=mail/mail-session=MyMail:add(jndi-name="java:/mail/myMail", from="jane.doe@gmail.example.com", debug=true)

Add a reference from “MyMail” to “MyMailSMTP”

  • SMTP server username
  • SMTP server password
  • TLS flag
  • SSL flag
/subsystem=mail/mail-session=MyMail/server=smtp:add( \
outbound-socket-binding-ref=MyMailSMTP, \
ssl=true, \
username=jane.doe@gmail.example.com, \
password=***)

Example Servlet sends a mail

@WebServlet("/")
public class MailServlet extends HttpServlet {
    @Resource(lookup = "java:/mail/myMail")
    Session session;

    protected void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
        MimeMessage message = new MimeMessage(session);
        try {

            InternetAddress[] address = { new InternetAddress("jane.doe@icloud.example.com") };
            message.setRecipients(Message.RecipientType.TO, address);
            message.setSubject("test");
            message.setSentDate(new Date());
            message.setText("testbody");
            Transport.send(message);
        } catch (MessagingException ex) {
            throw new ServletException(ex);
        }
    }
}

Mail which sent from WildFly

Debug Log

15:37:26,305 INFO  [stdout] (default task-1) DEBUG: JavaMail version 1.5.1
15:37:26,306 INFO  [stdout] (default task-1) DEBUG: successfully loaded resource: /META-INF/javamail.default.providers
15:37:26,307 INFO  [stdout] (default task-1) DEBUG: Tables of loaded providers
15:37:26,307 INFO  [stdout] (default task-1) DEBUG: Providers Listed By Class Name: {com.sun.mail.smtp.SMTPSSLTransport=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Oracle], com.sun.mail.smtp.SMTPTransport=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Oracle], com.sun.mail.imap.IMAPSSLStore=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Oracle], com.sun.mail.pop3.POP3SSLStore=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Oracle], com.sun.mail.imap.IMAPStore=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle], com.sun.mail.pop3.POP3Store=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Oracle]}
15:37:26,307 INFO  [stdout] (default task-1) DEBUG: Providers Listed By Protocol: {imaps=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Oracle], imap=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle], smtps=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Oracle], pop3=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Oracle], pop3s=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Oracle], smtp=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Oracle]}
15:37:26,307 INFO  [stdout] (default task-1) DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map
15:37:26,309 INFO  [stdout] (default task-1) DEBUG: getProvider() returning javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Oracle]
15:37:26,309 INFO  [stdout] (default task-1) DEBUG SMTP: need username and password for authentication
15:37:26,309 INFO  [stdout] (default task-1) DEBUG SMTP: useEhlo true, useAuth true
15:37:26,309 INFO  [stdout] (default task-1) DEBUG SMTP: trying to connect to host "smtp.gmail.com", port 465, isSSL true
15:37:26,889 INFO  [stdout] (default task-1) 220 mx.google.com ESMTP *** - gsmtp
15:37:26,889 INFO  [stdout] (default task-1) DEBUG SMTP: connected to host "smtp.gmail.com", port: 465
15:37:26,889 INFO  [stdout] (default task-1) 
15:37:26,893 INFO  [stdout] (default task-1) EHLO ***
15:37:27,006 INFO  [stdout] (default task-1) 250-mx.google.com at your service, [27.114.70.39]
15:37:27,006 INFO  [stdout] (default task-1) 250-SIZE 35882577
15:37:27,006 INFO  [stdout] (default task-1) 250-8BITMIME
15:37:27,006 INFO  [stdout] (default task-1) 250-AUTH LOGIN PLAIN XOAUTH XOAUTH2 PLAIN-CLIENTTOKEN
15:37:27,007 INFO  [stdout] (default task-1) 250-ENHANCEDSTATUSCODES
15:37:27,007 INFO  [stdout] (default task-1) 250 CHUNKING
15:37:27,007 INFO  [stdout] (default task-1) DEBUG SMTP: Found extension "SIZE", arg "35882577"
15:37:27,007 INFO  [stdout] (default task-1) DEBUG SMTP: Found extension "8BITMIME", arg ""
15:37:27,007 INFO  [stdout] (default task-1) DEBUG SMTP: Found extension "AUTH", arg "LOGIN PLAIN XOAUTH XOAUTH2 PLAIN-CLIENTTOKEN"
15:37:27,008 INFO  [stdout] (default task-1) DEBUG SMTP: Found extension "ENHANCEDSTATUSCODES", arg ""
15:37:27,008 INFO  [stdout] (default task-1) DEBUG SMTP: Found extension "CHUNKING", arg ""
15:37:27,008 INFO  [stdout] (default task-1) DEBUG SMTP: Attempt to authenticate using mechanisms: LOGIN PLAIN DIGEST-MD5 NTLM 
15:37:27,008 INFO  [stdout] (default task-1) DEBUG SMTP: AUTH LOGIN command trace suppressed
15:37:27,959 INFO  [stdout] (default task-1) DEBUG SMTP: AUTH LOGIN succeeded
15:37:27,960 INFO  [stdout] (default task-1) DEBUG SMTP: use8bit false
15:37:27,960 INFO  [stdout] (default task-1) MAIL FROM:<jane.doe@gmail.example.com>
15:37:28,074 INFO  [stdout] (default task-1) 250 2.1.0 OK *** - gsmtp
15:37:28,074 INFO  [stdout] (default task-1) RCPT TO:<jane.doe@icloud.example.com>
15:37:28,194 INFO  [stdout] (default task-1) 250 2.1.5 OK *** - gsmtp
15:37:28,195 INFO  [stdout] (default task-1) DEBUG SMTP: Verified Addresses
15:37:28,195 INFO  [stdout] (default task-1) DEBUG SMTP:   jane.doe@icloud.example.com
15:37:28,195 INFO  [stdout] (default task-1) DATA
15:37:28,881 INFO  [stdout] (default task-1) 354  Go ahead *** - gsmtp
15:37:28,881 INFO  [stdout] (default task-1) Date: Thu, 6 Mar 2014 15:37:26 +0900 (JST)
15:37:28,881 INFO  [stdout] (default task-1) To: jane.doe@icloud.example.com
15:37:28,881 INFO  [stdout] (default task-1) Message-ID: <56980149.1.1394087846308.JavaMail.jane.doe@gmail.example.com>
15:37:28,882 INFO  [stdout] (default task-1) Subject: test
15:37:28,882 INFO  [stdout] (default task-1) MIME-Version: 1.0
15:37:28,882 INFO  [stdout] (default task-1) Content-Type: text/plain; charset=us-ascii
15:37:28,882 INFO  [stdout] (default task-1) Content-Transfer-Encoding: 7bit
15:37:28,882 INFO  [stdout] (default task-1) 
15:37:28,882 INFO  [stdout] (default task-1) testbody
15:37:28,883 INFO  [stdout] (default task-1) .
15:37:29,802 INFO  [stdout] (default task-1) 250 2.0.0 OK 1394087849 *** - gsmtp
15:37:29,803 INFO  [stdout] (default task-1) QUIT
15:37:29,916 INFO  [stdout] (default task-1) 221 2.0.0 closing connection *** - gsmtp
  • Debug logging can be turned off like this:
/subsystem=mail/mail-session=MyMail:write-attribute(name=debug, value=false)
/:reload

References

  1. How to configure a Mail Session in Wildfly? | Community
  2. JBoss AS 7.2.0 Email Session configurtion - Eng… | Community
  3. jboss7.x - Please help configure JBoss 7 “mail-session” via jboss-cli - Stack Overflow
  4. Configuring and Using mail service in JBoss AS7 « JBoss
  5. JBoss 7 JavaMail | Community