JBatch and Postgresql db as job repository fails #195

tosuns · 2015-02-04T18:15:50Z

I'm currently testing payara 4.1.151 with a local postgresql db as job repository, but everytime when my batch-job get executed, I get the following exception:

Warnung: Caught throwable in main execution loop with Throwable message: null, and stack trace: java.lang.NullPointerException
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.updateBatchStatus(BaseStepControllerImpl.java:282)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markStepFailed(BaseStepControllerImpl.java:238)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markJobAndStepFailed(BaseStepControllerImpl.java:243)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.execute(BaseStepControllerImpl.java:128)
at com.ibm.jbatch.container.impl.ExecutionTransitioner.doExecutionLoop(ExecutionTransitioner.java:112)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.originateExecutionOnThread(JobThreadRootControllerImpl.java:110)
at com.ibm.jbatch.container.util.BatchWorkUnit.run(BatchWorkUnit.java:80)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.glassfish.enterprise.concurrent.internal.ManagedFutureTask.run(ManagedFutureTask.java:141)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)

Warnung: Caught throwable from run(). Stack trace: java.lang.IllegalStateException: Couldn't find entry to update for id = 1
at com.ibm.jbatch.container.services.impl.JobStatusManagerImpl.updateJobBatchStatus(JobStatusManagerImpl.java:82)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.persistJobBatchAndExitStatus(JobThreadRootControllerImpl.java:214)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.endOfJob(JobThreadRootControllerImpl.java:200)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.originateExecutionOnThread(JobThreadRootControllerImpl.java:128)
at com.ibm.jbatch.container.util.BatchWorkUnit.run(BatchWorkUnit.java:80)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.glassfish.enterprise.concurrent.internal.ManagedFutureTask.run(ManagedFutureTask.java:141)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)

Warnung: Caught throwable in main execution loop with Throwable message: null, and stack trace: java.lang.NullPointerException
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.updateBatchStatus(BaseStepControllerImpl.java:282)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markStepFailed(BaseStepControllerImpl.java:238)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markJobAndStepFailed(BaseStepControllerImpl.java:243)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.execute(BaseStepControllerImpl.java:128)
at com.ibm.jbatch.container.impl.ExecutionTransitioner.doExecutionLoop(ExecutionTransitioner.java:112)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.originateExecutionOnThread(JobThreadRootControllerImpl.java:110)
at com.ibm.jbatch.container.util.BatchWorkUnit.run(BatchWorkUnit.java:80)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.glassfish.enterprise.concurrent.internal.ManagedFutureTask.run(ManagedFutureTask.java:141)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)

To reproduce this bug, you have to do the following:

create a simple web-batch app: in my case a simple batchlet with a simple system.out output line. The job gets started via a ejb singleton, which is scheduled for every 5 secs.
create a db which contains the jsr352 schema via the provided jsr352 postgresql sql script.
configure payara to use the postgresql db as job repository via the admin console "Batch/Config".
deploy the app from step 1 to payara

The strange part is, if you set the logging for "fish.payara.jbatch.persistence.rdbms" to FINEST you can avoid the exception above, but this is not reliable. sometimes an exception gets thrown anyway.
For me it seems like some kind of raise-condition occurs.

smillidge · 2015-02-05T22:42:14Z

Could you let me know your configuration. I have tested a simple batch application on Postgres and it seems to work.

Connection pool Settings are;

ResourceType: javax.sql.DataSource
DataSource ClassName: org.postgresql.ds.PGSimpleDataSource
AdditionalProperties Tab: databaseName = jbatch (the name of the database that contains your jbatch tables
user = user
password = password

In my JBatch runtime configuration
Select JNDI name of the JDBC Resource that refers to the connection pool above
Database schema name: public
Table prefix and table suffix: both blank.

Postgres JDBC driver installed in glassfish/domains/domain1/lib

smillidge · 2015-02-05T22:53:34Z

Reproduced using Cargo tracker
[#|2015-02-05T22:52:00.051+0000|INFO|Payara 4.1|net.java.cargotracker.interfaces.handling.file.FileProcessorJobListener|_ThreadID=221;_ThreadName=concurrent/__defaultManagedExecutorService-managedThreadFactory-Thread-2;_TimeMillis=1423176720051;_LevelValue=800;|
Handling event file processor batch job starting at 05/02/15 22:52|#]

[#|2015-02-05T22:52:00.058+0000|WARNING|Payara 4.1|com.ibm.jbatch.container.impl.JobThreadRootControllerImpl|_ThreadID=221;_ThreadName=concurrent/__defaultManagedExecutorService-managedThreadFactory-Thread-2;_TimeMillis=1423176720058;_LevelValue=900;|
Caught throwable in main execution loop with Throwable message: null, and stack trace: java.lang.NullPointerException
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.updateBatchStatus(BaseStepControllerImpl.java:282)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markStepFailed(BaseStepControllerImpl.java:238)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.markJobAndStepFailed(BaseStepControllerImpl.java:243)
at com.ibm.jbatch.container.impl.BaseStepControllerImpl.execute(BaseStepControllerImpl.java:128)
at com.ibm.jbatch.container.impl.ExecutionTransitioner.doExecutionLoop(ExecutionTransitioner.java:112)
at com.ibm.jbatch.container.impl.JobThreadRootControllerImpl.originateExecutionOnThread(JobThreadRootControllerImpl.java:110)
at com.ibm.jbatch.container.util.BatchWorkUnit.run(BatchWorkUnit.java:80)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.glassfish.enterprise.concurrent.internal.ManagedFutureTask.run(ManagedFutureTask.java:141)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)
|#]

davewinters · 2015-02-06T18:29:47Z

Reproduced also using cargo tracker but not using the jbatch payroll and job-operator-api samples.

davewinters · 2015-02-09T11:47:05Z

Error in not seen on other databases such as Oracle, MySQL and derby etc

davewinters · 2015-03-04T12:24:59Z

Oracle 11g which I tested with also has the transaction isolation set to read_committed so both postgres and oracle have the same transaction isolation level. Change also the tx isolation for the jbatch postgres pool to serializable and the same issue occurs.

davewinters · 2015-03-04T15:06:33Z

This issue is timing related as already noted. I believe this is what is happening we have two transactions, one is attempting to insert/update a row in the jobstatus table (tx1) while at the same time a select is done to retrieve the value of this row in another transaction (tx2). Since tx2 has started before tx1 has committed its data to the jobstatus table then we receive a NullPointerException since no value is present in the jobstatus table.

The only way I believe to properly fix this issue is to ensure that when the SELECT is done to read the job status row value that updates to the JOBSTATUS table row data are done in the same transaction as we the select can view uncommitted changes if they are in the same transaction.

From the postgres 9.3 docs
Read Committed is the default isolation level in PostgreSQL. When a transaction uses this isolation level, a SELECT query (without a FOR UPDATE/SHARE clause) sees only data committed before the query began; it never sees either uncommitted data or changes committed during query execution by concurrent transactions.

Thoughts??

tosuns changed the title ~~JBatch and Postgresql don~~ JBatch and Postgresql db as job repository fails Feb 4, 2015

smillidge added payara bug and removed payara bug labels Feb 4, 2015

smillidge added payara bug and removed try to reproduce labels Feb 5, 2015

smillidge added this to the Payara Server 4.1.152 milestone Feb 5, 2015

smillidge assigned davewinters Feb 5, 2015

smillidge modified the milestones: Payara Server 4.1.153, Payara Server 4.1.152 Apr 14, 2015

smillidge modified the milestones: Payara Server 4.1.154, Payara Server 4.1.153 Aug 15, 2015

davidweaver mentioned this issue Nov 12, 2015

Payara 222 #521

Merged

smillidge modified the milestones: Payara Server 4.1.161, Payara Server 4.1.154 Nov 19, 2015

Pandrex247 closed this as completed in #521 Nov 30, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

JBatch and Postgresql db as job repository fails #195

JBatch and Postgresql db as job repository fails #195

tosuns commented Feb 4, 2015

smillidge commented Feb 5, 2015

smillidge commented Feb 5, 2015

davewinters commented Feb 6, 2015

davewinters commented Feb 9, 2015

davewinters commented Mar 4, 2015

davewinters commented Mar 4, 2015

JBatch and Postgresql db as job repository fails #195

JBatch and Postgresql db as job repository fails #195

Comments

tosuns commented Feb 4, 2015

smillidge commented Feb 5, 2015

smillidge commented Feb 5, 2015

davewinters commented Feb 6, 2015

davewinters commented Feb 9, 2015

davewinters commented Mar 4, 2015

davewinters commented Mar 4, 2015