Chunk方式のStepで例外発生時にスキップさせてみる
TweetPosted on Monday Feb 10, 2014 at 06:56PM in Technology
例外発生時のスキップをさせてみてどんな挙動か確認してみる
環境・前提条件
- jBeret 1.0.1.Beta-SNAPSHOT (1.0.0.FinalはSkipに不具合があるため)
- 他はChunk方式のStepを使ってみると同じ。この記事で作ったプロジェクトや資源がすでに存在するものとする
バッチを作る
仕様
- 入力、出力、処理内容は基本的にChunk方式のStepを使ってみるでやったのと同じ
- 6件目のデータ処理時にItemReaderでRuntimeExceptionが起こる
- RuntimeExceptionはskippable-exception-classesに指定されているので、ここだけスキップされる
資源
資源はこのへんにまとめて全部ある
- バッチ本体
- テスト
動かしてみる
ログ
11:18:00,247 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) open(): checkpoint=null, index starts at=0
11:18:00,250 DEBUG [org.hibernate.SQL] (batch-batch - 2) select chunkinput0_.id as id1_0_, chunkinput0_.input as input2_0_, chunkinput0_.processed as processe3_0_ from ChunkInputItem chunkinput0_ order by chunkinput0_.id
11:18:00,253 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) open(): checkpoint=null, index starts at=0
11:18:00,254 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=0, failAt=5
11:18:00,254 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=0, input=0, processed=false]
11:18:00,254 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=0, input=0, processed=false], output=ChunkOutputItem [id=0, result=0]
11:18:00,254 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=1
11:18:00,254 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=1, failAt=5
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=1, input=10, processed=false]
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=1, input=10, processed=false], output=ChunkOutputItem [id=1, result=5]
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=2
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=2, failAt=5
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=2, input=20, processed=false]
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=2, input=20, processed=false], output=ChunkOutputItem [id=2, result=10]
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=3
11:18:00,255 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): index=0
11:18:00,256 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=0, result=0]
11:18:00,256 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=1, result=5]
11:18:00,256 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=2, result=10]
11:18:00,256 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=3
11:18:00,256 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) checkpointInfo(): returns=1
11:18:00,258 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=3
11:18:00,261 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,262 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,263 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=3, failAt=5
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=3, input=30, processed=false]
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=3, input=30, processed=false], output=ChunkOutputItem [id=3, result=15]
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=4
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=4, failAt=5
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=4, input=40, processed=false]
11:18:00,292 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=4, input=40, processed=false], output=ChunkOutputItem [id=4, result=20]
11:18:00,293 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=5
11:18:00,293 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=5, failAt=5
11:18:00,293 WARNING [org.nailedtothex.jbatch.example.chunkskip.MySkipReadListener] (batch-batch - 2) onSkipReadItem(): java.lang.RuntimeException: 5
at org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader.readItem(ChunkSkipItemReader.java:43) [classes:]
at org.jberet.runtime.runner.ChunkRunner.readItem(ChunkRunner.java:343) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
at org.jberet.runtime.runner.ChunkRunner.readProcessWriteItems(ChunkRunner.java:288) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
at org.jberet.runtime.runner.ChunkRunner.run(ChunkRunner.java:190) [jberet-core-1.0.1.Beta-SNAPSHOT.jar:1.0.1.Beta-SNAPSHOT]
at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:204) [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)
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=6
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=6, failAt=5
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=6, input=60, processed=false]
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=6, input=60, processed=false], output=ChunkOutputItem [id=6, result=30]
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=7
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): index=1
11:18:00,294 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=3, result=15]
11:18:00,295 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=4, result=20]
11:18:00,295 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=6, result=30]
11:18:00,295 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=7
11:18:00,295 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) checkpointInfo(): returns=2
11:18:00,297 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=7
11:18:00,297 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,298 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,299 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=7, failAt=5
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=7, input=70, processed=false]
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=7, input=70, processed=false], output=ChunkOutputItem [id=7, result=35]
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=8
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=8, failAt=5
11:18:00,328 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=8, input=80, processed=false]
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=8, input=80, processed=false], output=ChunkOutputItem [id=8, result=40]
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=9
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=9, failAt=5
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=ChunkInputItem [id=9, input=90, processed=false]
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemProcessor] (batch-batch - 2) processItem(): input=ChunkInputItem [id=9, input=90, processed=false], output=ChunkOutputItem [id=9, result=45]
11:18:00,329 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=10
11:18:00,330 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): index=2
11:18:00,330 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=7, result=35]
11:18:00,330 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=8, result=40]
11:18:00,331 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) writeItems(): item=ChunkOutputItem [id=9, result=45]
11:18:00,332 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=10
11:18:00,332 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) checkpointInfo(): returns=3
11:18:00,334 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=10
11:18:00,334 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,335 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,336 DEBUG [org.hibernate.SQL] (batch-batch - 2) insert into ChunkOutputItem (result, id) values (?, ?)
11:18:00,364 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): index=10, failAt=5
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) readItem(): returning=null
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) checkpointInfo(): returns=10
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) close()
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) close()
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemReader] (batch-batch - 2) close()
11:18:00,365 FINE [org.nailedtothex.jbatch.example.chunkskip.ChunkSkipItemWriter] (batch-batch - 2) close()
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
----------------+---------------+---------+-------------------------+-------------------------+-------------------------+-------------------------+-------------+------------+----------------------+-----------------
124 | 119 | | 2014-02-15 11:18:00.243 | 2014-02-15 11:18:00.243 | 2014-02-15 11:18:00.367 | 2014-02-15 11:18:00.367 | COMPLETED | COMPLETED | itemReaderFailAt = 5+|
| | | | | | | | | divide = 2 +|
| | | | | | | | | |
(1 row)
jbatch=#
step_execution
jbatch=# select * from step_execution where jobexecutionid =124;
stepexecutionid | jobexecutionid | version | stepname | starttime | endtime | batchstatus | exitstatus | executionexception | persistentuserdata | readcount | writecount | commitcount | rollbackcount | readskipcount | processskipcount | filtercount | writeskipcount | readercheckpointinfo | writercheckpointinfo
-----------------+----------------+---------+----------+-------------------------+-------------------------+-------------+------------+--------------------+--------------------+-----------+------------+-------------+---------------+---------------+------------------+-------------+----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------
139 | 124 | | doChunk | 2014-02-15 11:18:00.244 | 2014-02-15 11:18:00.365 | COMPLETED | COMPLETED | | | 9 | 9 | 4 | 0 | 1 | 0 | 0 | 0 | \xaced0005737200116a6176612e6c616e672e496e746567657212e2a0a4f781873802000149000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b02000078700000000a | \xaced0005737200116a6176612e6c616e672e496e746567657212e2a0a4f781873802000149000576616c7565787200106a6176612e6c616e672e4e756d62657286ac951d0b94e08b020000787000000003
(1 row)
jbatch=#
テーブル出力
スキップ対象の1件以外は正常に出ている。うむ
jbatcharts=# select * from chunkoutputitem order by id; id | result ----+-------- 0 | 0 1 | 5 2 | 10 3 | 15 4 | 20 6 | 30 7 | 35 8 | 40 9 | 45 (9 rows) jbatcharts=#
参考文献
Tags: jbatch
