1. Zuhause
  2. Frage und Antwort
  3. Spring Batch Process hängt nach dem Schreiber abgeschlossen

Spring Batch Process hängt nach dem Schreiber abgeschlossen

2016-08-30 2 views
1

Ich bin ratlos, wie dieses Problem zu debuggen, so nicht einmal sicher, welche Code-Schnipsel aufstellen. Hier ist die grundlegende Einrichtung:Spring Batch Process hängt nach dem Schreiber abgeschlossen

Ich muss von einer REST-API lesen und in eine SOAP-API schreiben. Soweit ich das beurteilen kann, funktionieren Lesen und Schreiben ohne Probleme. Ich habe 3 Sätze mit 3 passende Sätze schreibt liest, die parallel passieren kann, so dass ich sie mit dem FlowBuilder aufgebaut haben wie so:

final Flow firstFlow = new FlowBuilder<Flow>("firstFlow").from(Step1).end(); 
final Flow secondFlow = new FlowBuilder<Flow>("secondFlow").from(Step2).end(); 
final Flow thirdFlow = new FlowBuilder<Flow>("thirdFlow").from(Step3).end(); 

Flow mdmFlow = builder2.split(new SimpleAsyncTaskExecutor()).add(firstFlow, secondFlow, thirdFlow).build(); 
FlowBuilder<SimpleFlow> builder2 = new FlowBuilder<SimpleFlow>("attribsAndItemsFlow");

Dann baue ich es wie so:

return jobs.get("feedControlJob") 
       .incrementer(new RunIdIncrementer()) 
       .listener(listener) 
       .preventRestart() 
       .start(mdmFlow) 
       .end() 
       .build();

In der Hörer ich habe:

public void beforeJob(JobExecution jobExecution) { 
    log.info("Starting Batch Job..."); 
}

, die die Zeile im Protokoll gesetzt hat, so dass ich weiß, dass der Hörer richtig geladen wird. Ich habe auch:

Das log.info läuft nie, also bin ich sicher, dass es nicht dort ankommt. Die letzte Zeile meines Schreibers ist jedoch:

log.debug("Finished writes.");

Das schreibt in das Protokoll für alle drei Flüsse. Wenn ich versuche, mit dem Debugger durchzulaufen, lande ich schnell in Codeabschnitten, für die STS keine Quelle hat.

Am besten kann ich sagen, dass irgendwo zwischen dem Ende des letzten Writer-Exits und vor dem After-Job-Ereignis etwas falsch ist. Ich bekomme keine Fehler in der Konsole.

ich es mit Protokollebene lief zu debuggen gesetzt, hier ist die Ausgabe mit meiner letzten Codezeile starten:

2016-08-30 16:46:37.046 DEBUG 11260 --- [cTaskExecutor-2] com.dcsg.writeobject.MdmItemWriterClass : Finished writes. 
2016-08-30 16:46:37.046 DEBUG 11260 --- [cTaskExecutor-2] o.s.b.c.step.item.ChunkOrientedTasklet : Inputs not busy, ended: true 
2016-08-30 16:46:37.046 DEBUG 11260 --- [cTaskExecutor-2] o.s.batch.core.step.tasklet.TaskletStep : Applying contribution: [StepContribution: read=20, written=20, filtered=0, readSkips=0, writeSkips=0, processSkips=0, exitStatus=EXECUTING] 
2016-08-30 16:46:37.046 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Participating in existing transaction 
2016-08-30 16:46:37.047 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
2016-08-30 16:46:37.047 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?] 
2016-08-30 16:46:37.048 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
2016-08-30 16:46:37.049 DEBUG 11260 --- [cTaskExecutor-2] o.s.batch.core.step.tasklet.TaskletStep : Saving step execution before commit: StepExecution: id=0, version=1, name=GG Step, status=STARTED, exitStatus=EXECUTING, readCount=20, filterCount=0, writeCount=20 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0, exitDescription= 
2016-08-30 16:46:37.049 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Participating in existing transaction 
2016-08-30 16:46:37.049 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
2016-08-30 16:46:37.049 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?] 
2016-08-30 16:46:37.050 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
2016-08-30 16:46:37.050 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL query 
2016-08-30 16:46:37.050 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?] 
2016-08-30 16:46:37.051 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Initiating transaction commit 
2016-08-30 16:46:37.051 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Committing JDBC transaction on Connection [[email protected]] 
2016-08-30 16:46:37.051 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Releasing JDBC Connection [[email protected]] after transaction 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.batch.repeat.support.RepeatTemplate : Repeat is complete according to policy and result value. 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.batch.core.step.AbstractStep   : Step execution success: id=0 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.datasource.SimpleDriverDataSource : Creating new JDBC Driver Connection to [jdbc:hsqldb:mem:testdb] 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Acquired Connection [[email protected]] for JDBC transaction 
2016-08-30 16:46:37.052 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Switching JDBC Connection [[email protected]] to manual commit 
2016-08-30 16:46:37.053 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
2016-08-30 16:46:37.053 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?] 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Initiating transaction commit 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Committing JDBC transaction on Connection [[email protected]] 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Releasing JDBC Connection [[email protected]] after transaction 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.datasource.SimpleDriverDataSource : Creating new JDBC Driver Connection to [jdbc:hsqldb:mem:testdb] 
2016-08-30 16:46:37.054 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Acquired Connection [[email protected]] for JDBC transaction 
2016-08-30 16:46:37.055 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Switching JDBC Connection [[email protected]] to manual commit 
2016-08-30 16:46:37.055 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
2016-08-30 16:46:37.055 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?] 
2016-08-30 16:46:37.056 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
2016-08-30 16:46:37.056 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL query 
2016-08-30 16:46:37.056 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?] 
2016-08-30 16:46:37.056 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Initiating transaction commit 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Committing JDBC transaction on Connection [[email protected]] 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Releasing JDBC Connection [[email protected]] after transaction 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.batch.core.step.AbstractStep   : Step execution complete: StepExecution: id=0, version=3, name=GG Step, status=COMPLETED, exitStatus=COMPLETED, readCount=20, filterCount=0, writeCount=20 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.datasource.SimpleDriverDataSource : Creating new JDBC Driver Connection to [jdbc:hsqldb:mem:testdb] 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Acquired Connection [[email protected]] for JDBC transaction 
2016-08-30 16:46:37.057 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Switching JDBC Connection [[email protected]] to manual commit 
2016-08-30 16:46:37.058 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL update 
2016-08-30 16:46:37.058 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE JOB_EXECUTION_ID = ?] 
2016-08-30 16:46:37.058 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.core.JdbcTemplate    : SQL update affected 1 rows 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Initiating transaction commit 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Committing JDBC transaction on Connection [[email protected]] 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.j.d.DataSourceTransactionManager  : Releasing JDBC Connection [[email protected]] after transaction 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.jdbc.datasource.DataSourceUtils  : Returning JDBC Connection to DataSource 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.b.core.job.flow.support.SimpleFlow : Completed state=thirdFlow.GG Step with status=COMPLETED 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.b.core.job.flow.support.SimpleFlow : Handling state=thirdFlow.COMPLETED 
2016-08-30 16:46:37.059 DEBUG 11260 --- [cTaskExecutor-2] o.s.b.core.job.flow.support.SimpleFlow : Completed state=thirdFlow.COMPLETED with status=COMPLETED

Danach hängt es nur auf unbestimmte Zeit.

EDIT: Ein Thread-Dump wurde, angefordert hier so ist einer von während es hängt:

2016-09-01 13:42:00 
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.66-b18 mixed mode): 

"SimpleAsyncTaskExecutor-1" #16 prio=5 os_prio=0 tid=0x00000000211c2000 nid=0x157c runnable [0x000000001eb0d000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.SocketInputStream.socketRead0(Native Method) 
    at java.net.SocketInputStream.socketRead(Unknown Source) 
    at java.net.SocketInputStream.read(Unknown Source) 
    at java.net.SocketInputStream.read(Unknown Source) 
    at sun.security.ssl.InputRecord.readFully(Unknown Source) 
    at sun.security.ssl.InputRecord.read(Unknown Source) 
    at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source) 
    - locked <0x00000006c1eba630> (a java.lang.Object) 
    at sun.security.ssl.SSLSocketImpl.readDataRecord(Unknown Source) 
    at sun.security.ssl.AppInputStream.read(Unknown Source) 
    - locked <0x00000006c1ebb978> (a sun.security.ssl.AppInputStream) 
    at java.io.BufferedInputStream.fill(Unknown Source) 
    at java.io.BufferedInputStream.read1(Unknown Source) 
    at java.io.BufferedInputStream.read(Unknown Source) 
    - locked <0x00000006c1ebb950> (a java.io.BufferedInputStream) 
    at sun.net.www.http.HttpClient.parseHTTPHeader(Unknown Source) 
    at sun.net.www.http.HttpClient.parseHTTP(Unknown Source) 
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(Unknown Source) 
    - locked <0x00000006c1ef2178> (a sun.net.www.protocol.https.DelegateHttpsURLConnection) 
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source) 
    - locked <0x00000006c1ef2178> (a sun.net.www.protocol.https.DelegateHttpsURLConnection) 
    at java.net.HttpURLConnection.getResponseCode(Unknown Source) 
    at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(Unknown Source) 
    at org.springframework.http.client.SimpleClientHttpResponse.getRawStatusCode(SimpleClientHttpResponse.java:48) 
    at org.springframework.http.client.AbstractClientHttpResponse.getStatusCode(AbstractClientHttpResponse.java:33) 
    at org.springframework.web.client.DefaultResponseErrorHandler.getHttpStatusCode(DefaultResponseErrorHandler.java:56) 
    at org.springframework.web.client.DefaultResponseErrorHandler.hasError(DefaultResponseErrorHandler.java:50) 
    at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:629) 
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:597) 
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:557) 
    at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:475) 
    at com.dcsg.mdm.MdmItemItemReaderClass.getResultSetId(MdmItemItemReaderClass.java:173) 
    at com.dcsg.mdm.MdmItemItemReaderClass.init(MdmItemItemReaderClass.java:84) 
    at com.dcsg.mdm.MdmItemItemReaderClass.read(MdmItemItemReaderClass.java:107) 
    at com.dcsg.mdm.MdmItemItemReaderClass.read(MdmItemItemReaderClass.java:1) 
    at org.springframework.batch.core.step.item.SimpleChunkProvider.doRead(SimpleChunkProvider.java:91) 
    at org.springframework.batch.core.step.item.SimpleChunkProvider.read(SimpleChunkProvider.java:157) 
    at org.springframework.batch.core.step.item.SimpleChunkProvider$1.doInIteration(SimpleChunkProvider.java:116) 
    at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:374) 
    at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:215) 
    at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:144) 
    at org.springframework.batch.core.step.item.SimpleChunkProvider.provide(SimpleChunkProvider.java:110) 
    at org.springframework.batch.core.step.item.ChunkOrientedTasklet.execute(ChunkOrientedTasklet.java:69) 
    at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:406) 
    at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:330) 
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133) 
    at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:271) 
    at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:81) 
    at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:374) 
    at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:215) 
    at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:144) 
    at org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:257) 
    at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:200) 
    at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:148) 
    at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:64) 
    at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:67) 
    at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:169) 
    at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:144) 
    at org.springframework.batch.core.job.flow.support.state.SplitState$1.call(SplitState.java:93) 
    at org.springframework.batch.core.job.flow.support.state.SplitState$1.call(SplitState.java:90) 
    at java.util.concurrent.FutureTask.run(Unknown Source) 
    at java.lang.Thread.run(Unknown Source) 

"RMI TCP Accept-0" #13 daemon prio=5 os_prio=0 tid=0x000000001e36f800 nid=0xbf8 runnable [0x000000001f8df000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.DualStackPlainSocketImpl.accept0(Native Method) 
    at java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 
    at java.net.AbstractPlainSocketImpl.accept(Unknown Source) 
    at java.net.PlainSocketImpl.accept(Unknown Source) 
    - locked <0x00000006c0046480> (a java.net.SocksSocketImpl) 
    at java.net.ServerSocket.implAccept(Unknown Source) 
    at java.net.ServerSocket.accept(Unknown Source) 
    at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 
    at java.lang.Thread.run(Unknown Source) 

"RMI TCP Accept-26293" #12 daemon prio=5 os_prio=0 tid=0x000000001e381000 nid=0x15e0 runnable [0x000000001f7ae000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.DualStackPlainSocketImpl.accept0(Native Method) 
    at java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 
    at java.net.AbstractPlainSocketImpl.accept(Unknown Source) 
    at java.net.PlainSocketImpl.accept(Unknown Source) 
    - locked <0x00000006c00469e0> (a java.net.SocksSocketImpl) 
    at java.net.ServerSocket.implAccept(Unknown Source) 
    at java.net.ServerSocket.accept(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 
    at java.lang.Thread.run(Unknown Source) 

"RMI TCP Accept-0" #11 daemon prio=5 os_prio=0 tid=0x000000001e388800 nid=0x2ba4 runnable [0x000000001ed3e000] 
    java.lang.Thread.State: RUNNABLE 
    at java.net.DualStackPlainSocketImpl.accept0(Native Method) 
    at java.net.DualStackPlainSocketImpl.socketAccept(Unknown Source) 
    at java.net.AbstractPlainSocketImpl.accept(Unknown Source) 
    at java.net.PlainSocketImpl.accept(Unknown Source) 
    - locked <0x00000006c0046e70> (a java.net.SocksSocketImpl) 
    at java.net.ServerSocket.implAccept(Unknown Source) 
    at java.net.ServerSocket.accept(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(Unknown Source) 
    at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(Unknown Source) 
    at java.lang.Thread.run(Unknown Source) 

"Service Thread" #9 daemon prio=9 os_prio=0 tid=0x000000001e018000 nid=0x1e24 runnable [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"C1 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x000000001df94800 nid=0x28b0 waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x000000001df92800 nid=0x2150 waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001c89d000 nid=0x2d8c waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001c89b800 nid=0x2de4 waiting on condition [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001c898800 nid=0x2d18 runnable [0x0000000000000000] 
    java.lang.Thread.State: RUNNABLE 

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001c834000 nid=0x2988 in Object.wait() [0x000000001da1f000] 
    java.lang.Thread.State: WAITING (on object monitor) 
    at java.lang.Object.wait(Native Method) 
    - waiting on <0x00000006c0089980> (a java.lang.ref.ReferenceQueue$Lock) 
    at java.lang.ref.ReferenceQueue.remove(Unknown Source) 
    - locked <0x00000006c0089980> (a java.lang.ref.ReferenceQueue$Lock) 
    at java.lang.ref.ReferenceQueue.remove(Unknown Source) 
    at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source) 

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000001c832000 nid=0x2e58 in Object.wait() [0x000000001d90f000] 
    java.lang.Thread.State: WAITING (on object monitor) 
    at java.lang.Object.wait(Native Method) 
    - waiting on <0x00000006c00899c0> (a java.lang.ref.Reference$Lock) 
    at java.lang.Object.wait(Unknown Source) 
    at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source) 
    - locked <0x00000006c00899c0> (a java.lang.ref.Reference$Lock) 

"main" #1 prio=5 os_prio=0 tid=0x0000000002baa000 nid=0x2a64 waiting on condition [0x0000000002f7d000] 
    java.lang.Thread.State: WAITING (parking) 
    at sun.misc.Unsafe.park(Native Method) 
    - parking to wait for <0x00000006c1fc8ea0> (a java.util.concurrent.FutureTask) 
    at java.util.concurrent.locks.LockSupport.park(Unknown Source) 
    at java.util.concurrent.FutureTask.awaitDone(Unknown Source) 
    at java.util.concurrent.FutureTask.get(Unknown Source) 
    at org.springframework.batch.core.job.flow.support.state.SplitState.handle(SplitState.java:113) 
    at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:169) 
    at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:144) 
    at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:134) 
    at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:306) 
    at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:135) 
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50) 
    at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:128) 
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) 
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) 
    at java.lang.reflect.Method.invoke(Unknown Source) 
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302) 
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) 
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) 
    at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:127) 
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) 
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208) 
    at com.sun.proxy.$Proxy33.run(Unknown Source) 
    at org.springframework.boot.autoconfigure.batch.JobLauncherCommandLineRunner.execute(JobLauncherCommandLineRunner.java:216) 
    at org.springframework.boot.autoconfigure.batch.JobLauncherCommandLineRunner.executeLocalJobs(JobLauncherCommandLineRunner.java:233) 
    at org.springframework.boot.autoconfigure.batch.JobLauncherCommandLineRunner.launchJobFromProperties(JobLauncherCommandLineRunner.java:125) 
    at org.springframework.boot.autoconfigure.batch.JobLauncherCommandLineRunner.run(JobLauncherCommandLineRunner.java:119) 
    at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:800) 
    at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:784) 
    at org.springframework.boot.SpringApplication.afterRefresh(SpringApplication.java:771) 
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307) 
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1185) 
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1174) 
    at com.dcsg.mdm.MdmAttributeControlApplication.main(MdmAttributeControlApplication.java:28) 

"VM Thread" os_prio=2 tid=0x000000001c82c800 nid=0x2d14 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002bbe800 nid=0x2bd0 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002bc0000 nid=0x272c runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x0000000002bc2000 nid=0x1ca8 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x0000000002bc5800 nid=0x2b3c runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x000000001e371000 nid=0x2a00 waiting on condition 

JNI global references: 237

Quelle

2016-08-30 VydorScope

+0

Normalerweise baue ich Flüsse wie 'neuer FlowBuilder ("Name") .start (Schritt1) .build()'.Probieren Sie dies aus, anstatt "von" und "Ende" zu verwenden. Wahrscheinlich hilft es. –

+0

Vielen Dank für den Vorschlag. Ich habe meinen Code wie vorgeschlagen geändert, aber der Fehler tritt immer noch auf. – VydorScope

+0

Was ist mit den anderen zwei Threads (firstflow, secondflow)? Erreichen sie auch den Status "abgeschlossen"? Haben Sie versucht, Ihren Job nur mit normalen Lesern und Autoren zu implementieren (kein Rest und Soap - nur zum Testen)? –

Antwort

0

Es stellt sich heraus, dass zumindest in einigen Fällen RestTemplate.exchange() in einen Zustand kommen kann, wo es kommt nie zurück. In diesem Fall wird der ItemReader auch nie zurückgegeben und es werden keine Fehler gemeldet. Der Batch-Prozess erreicht das Ende und sieht, dass ein (oder mehrere) ItemReader-Prozess noch nicht abgeschlossen ist, und wartet unbegrenzt darauf, dass dieser Reader zurückkehrt. Ich habe es sogar über Nacht sitzen lassen, es gibt nie auf zu warten.

Ich löste dies, indem ich dem RestTemplate-Aufruf eine Zeitüberschreitung hinzufügte. Um den Timeout Sie wie so eine ClientHttpRequest erstellen müssen:

private ClientHttpRequestFactory getClientHttpRequestFactory() { 
     HttpComponentsClientHttpRequestFactory clientHttpRequestFactory = new HttpComponentsClientHttpRequestFactory(); 
     clientHttpRequestFactory.setConnectTimeout(this.timeout); 
     return clientHttpRequestFactory; 
    }

Wenn Sie dann den RestTemplage erstellen, tun Sie es wie so:

RestTemplate restTemplate = new RestTemplate(getClientHttpRequestFactory());

Ich hatte angenommen, dass die RestTemplate einige Standard-Timeout hatte , aber das scheint nicht der Fall zu sein.

Ich konnte dies dank Hansjoergs Vorschlag oben, um den Thread-Dump zu studieren, endlich aufspüren.

Quelle

2016-09-07 13:00:01 VydorScope

Verwandte Themen

 Verwandte Themen