6 Replies Latest reply on Sep 5, 2016 3:15 PM by karlnicholas

I get a SQL error ONLY when running as a scheduled service?

karlnicholas Sep 4, 2016 11:58 AM

I have a "large" update, maybe several hundred rows. My code works when I manually run it as a "JPA" console app, or when I attach the code to a commandButton, but not when I run it as a scheduled service.

The beans all use Container Managed Transactions, but I don't know if the transaction impl is different between the command-button invoked method vs. the scheduled service invoked method.

I get a mysql error SQL Error: 1452, SQLState: 23000.

At this point, looking for ideas and suggestions. How to debug, how to think about what might be causing the differences? This is wildfly 10.

Thank for any help.

1. Re: I get a SQL error ONLY when running as a scheduled service?

jaikiran Sep 4, 2016 1:14 PM (in response to karlnicholas)

Can you post the entire exception stacktrace? Also, what exactly is a scheduled service in the context of WildFly?
Actions
2. Re: I get a SQL error ONLY when running as a scheduled service?

karlnicholas Sep 4, 2016 1:18 PM (in response to jaikiran)

10:01:54,088 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 1) SQL Error: 1452, SQLState: 23000
10:01:54,088 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 1) Cannot add or update a child row: a foreign key constraint fails (`op`.`slipopinion_opinioncitations`, CONSTRAINT `FKnv3p7ky3646y8i4iixa1dtrw8` FOREIGN KEY (`slipopinion_page`, `slipopinion_volume`, `slipopinion_vset`) REFERENCES `slipopinion` (`page`, `volu)
10:01:54,113 INFO [org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl] (EJB default - 1) HHH000010: On release of batch it still contained JDBC statements
10:01:54,115 WARN [com.arjuna.ats.arjuna] (EJB default - 1) ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffffac1f6209:-65acf3d9:57cc52b9:10, org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList@78e83f5c >: javax.persistence.PersistenceException: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1608)
    at org.hibernate.jpa.internal.EntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(EntityManagerImpl.java:235)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2967)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2339)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:485)
    at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:316)
    at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
    at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
    at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:116)
    at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:371)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91)
    at org.jboss.as.ejb3.tx.TimerCMTTxInterceptor.endTransaction(TimerCMTTxInterceptor.java:67)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
    at org.jboss.as.ejb3.concurrency.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:110)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
    at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:104)
    at org.jboss.as.ejb3.timerservice.CalendarTimerTask.invokeBeanMethod(CalendarTimerTask.java:64)
    at org.jboss.as.ejb3.timerservice.CalendarTimerTask.callTimeout(CalendarTimerTask.java:53)
    at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:155)
    at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1221)
    at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:497)
    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.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:59)
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
    at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
    at org.hibernate.persister.collection.AbstractCollectionPersister.recreate(AbstractCollectionPersister.java:1313)
    at org.hibernate.action.internal.CollectionRecreateAction.execute(CollectionRecreateAction.java:50)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:560)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:434)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:465)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2963)
    ... 52 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Cannot add or update a child row: a foreign key constraint fails (`op`.`slipopinion_opinioncitations`, CONSTRAINT `FKnv3p7ky3646y8i4iixa1dtrw8` FOREIGN KEY (`slipopinion_page`, `slipopinion_volume`, `slipopinion_vset`) REFERENCES `slipopinion` (`page`, `volu)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:408)
    at com.mysql.jdbc.Util.getInstance(Util.java:383)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1049)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4226)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4158)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2840)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2082)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2334)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2262)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2246)
    at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
    ... 62 more

10:01:54,120 ERROR [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0020: Error invoking timeout for timer: [id=d747e662-c0ed-4b45-8147-ea28d46b4e3c timedObjectId=opca-ear.opca-ejb.ScheduledService auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@40ce6c97 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Mon Sep 05 10:00:00 PDT 2016 timerState=IN_TIMEOUT info=null]: javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:137)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:117)
    at org.jboss.as.ejb3.tx.TimerCMTTxInterceptor.endTransaction(TimerCMTTxInterceptor.java:67)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
    at org.jboss.as.ejb3.concurrency.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:110)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
    at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:104)
    at org.jboss.as.ejb3.timerservice.CalendarTimerTask.invokeBeanMethod(CalendarTimerTask.java:64)
    at org.jboss.as.ejb3.timerservice.CalendarTimerTask.callTimeout(CalendarTimerTask.java:53)
    at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:155)
    at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1221)
    at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:497)
    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.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1212)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91)
    ... 38 more
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1692)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1608)
    at org.hibernate.jpa.internal.EntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(EntityManagerImpl.java:235)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2967)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2339)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:485)
    at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:316)
    at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
    at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
    at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:116)
    at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:371)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)
    ... 41 more
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:59)
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207)
    at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:45)
    at org.hibernate.persister.collection.AbstractCollectionPersister.recreate(AbstractCollectionPersister.java:1313)
    at org.hibernate.action.internal.CollectionRecreateAction.execute(CollectionRecreateAction.java:50)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:560)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:434)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1282)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:465)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:2963)
    ... 52 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Cannot add or update a child row: a foreign key constraint fails (`op`.`slipopinion_opinioncitations`, CONSTRAINT `FKnv3p7ky3646y8i4iixa1dtrw8` FOREIGN KEY (`slipopinion_page`, `slipopinion_volume`, `slipopinion_vset`) REFERENCES `slipopinion` (`page`, `volu)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:408)
    at com.mysql.jdbc.Util.getInstance(Util.java:383)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1049)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4226)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4158)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2776)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2840)
    at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2082)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2334)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2262)
    at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2246)
    at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204)
    ... 62 more

10:01:54,122 INFO [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0021: Timer: [id=d747e662-c0ed-4b45-8147-ea28d46b4e3c timedObjectId=opca-ear.opca-ejb.ScheduledService auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@40ce6c97 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Mon Sep 05 10:00:00 PDT 2016 timerState=IN_TIMEOUT info=null] will be retried
10:01:54,122 INFO [org.jboss.as.ejb3] (EJB default - 1) WFLYEJB0023: Retrying timeout for timer: [id=d747e662-c0ed-4b45-8147-ea28d46b4e3c timedObjectId=opca-ear.opca-ejb.ScheduledService auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@40ce6c97 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Mon Sep 05 10:00:00 PDT 2016 timerState=IN_TIMEOUT info=null]
10:01:54,123 INFO [opca.service.ScheduledService] (EJB default - 1) STARTING SCRAPER UPDATE
10:01:54,123 INFO [opca.scraper.CACaseScraper] (EJB default - 1) CACaseScraper
10:01:54,877 WARNING [opca.scraper.CACaseScraper] (EJB default - 1) Duplicate Detected:D068384M : 06/23/16 : P. V. JOHNSON
10:01:54,878 WARNING [opca.scraper.CACaseScraper] (EJB default - 1) Duplicate Detected:B261860M : 06/23/16 : RICE V. DOWNS
10:01:54,879 WARNING [opca.scraper.CACaseScraper] (EJB default - 1) Duplicate Detected:H041157M : 06/22/16 : P. V. OCEGUEDA
10:01:54,885 WARNING [opca.scraper.CACaseScraper] (EJB default - 1) Duplicate Detected:H040268M : 06/10/16 : SEIBERT V. CITY OF SAN JOSE
10:01:55,130 INFO [opca.service.updates.CAOnlineUpdates] (EJB default - 1) Found 346 in the database.
10:01:55,130 INFO [opca.service.updates.CAOnlineUpdates] (EJB default - 1) Split Transactions
10:01:55,131 INFO [opca.service.updates.CAOnlineUpdates] (EJB default - 1) No cases deleted.
10:01:55,131 INFO [opca.service.updates.CAOnlineUpdates] (EJB default - 1) No new cases.
10:01:55,131 INFO [opca.service.ScheduledService] (EJB default - 1) DONE SCRAPER UPDATE
10:02:11,456 INFO [org.jboss.as.server] (management-handler-thread - 6) WFLYSRV0211: Suspending server with 0ms timeout.
10:02:11,857 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested.
10:02:13,025 INFO [org.wildfly.extension.undertow] (ServerService Thread Pool -- 80) WFLYUT0022: Unregistered web context: /opca-web
10:02:13,444 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0019: Host default-host stopping
10:02:13,445 INFO [org.jboss.weld.deployer] (MSC service thread 1-2) WFLYWELD0010: Stopping weld service for deployment opca-ear.ear
10:02:13,575 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-2) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
10:02:13,610 INFO [org.jboss.as.jpa] (ServerService Thread Pool -- 81) WFLYJPA0011: Stopping Persistence Unit (phase 2 of 2) Service 'opca-ear.ear/opca-ejb.jar#opee'
10:02:13,689 INFO [org.jboss.as.jpa] (ServerService Thread Pool -- 88) WFLYJPA0011: Stopping Persistence Unit (phase 1 of 2) Service 'opca-ear.ear/opca-ejb.jar#opee'
10:02:13,691 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-8) WFLYJCA0010: Unbound data source [java:jboss/datasources/OpEEDS]
10:02:13,699 INFO [org.jboss.as.server.deployment] (MSC service thread 1-7) WFLYSRV0208: Stopped subdeployment (runtime-name: opca-ejb.jar) in 1611ms
10:02:13,720 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 81) WFLYCLINF0003: Stopped client-mappings cache from ejb container
10:02:13,723 INFO [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0008: Undertow HTTP listener default suspending
10:02:13,726 INFO [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 127.0.0.1:8080
10:02:13,812 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0019: Stopped Driver service with driver-name = h2
10:02:13,816 INFO [org.wildfly.extension.undertow] (MSC service thread 1-3) WFLYUT0004: Undertow 1.3.15.Final stopping
10:02:13,981 INFO [org.jboss.as.server.deployment] (MSC service thread 1-7) WFLYSRV0208: Stopped subdeployment (runtime-name: opca-web.war) in 1893ms
10:02:14,210 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-6) WFLYJCA0019: Stopped Driver service with driver-name = mysql
10:02:14,253 INFO [org.jboss.as.server.deployment] (MSC service thread 1-4) WFLYSRV0028: Stopped deployment opca-ear.ear (runtime-name: opca-ear.ear) in 2181ms
10:02:14,681 INFO [org.jboss.as] (MSC service thread 1-8) WFLYSRV0050: WildFly Full 10.0.0.Final (WildFly Core 2.0.10.Final) stopped in 2629ms
Actions
3. Re: I get a SQL error ONLY when running as a scheduled service?

karlnicholas Sep 4, 2016 1:20 PM (in response to jaikiran)

This is a scheduled service

@Schedule(second="0", minute="0", hour="10", persistent=false)   // 01:00 am every day
    public void updateSlipOpinions() {
   logger.info("STARTING SCRAPER UPDATE");
   caOnlineUpdates.updateDatabase(new TestCACaseScraper(false));
   logger.info("DONE SCRAPER UPDATE");
    }
Actions
4. Re: I get a SQL error ONLY when running as a scheduled service?

mayerw01 Sep 5, 2016 6:35 AM (in response to karlnicholas)

Looks like a consistency issue.
Maybe you can try this approach JPA, MySQL and concurrency problem
Actions
5. Re: I get a SQL error ONLY when running as a scheduled service?

karlnicholas Sep 5, 2016 1:36 PM (in response to mayerw01)

I've made some progress and the issue is related to an embedded collection of composite foreign keys not cascading during a delete for some reason. It's no problem with an EntityTranaction but there's a problem with a UserTransaction. I'm trying to see if I can make a minimal reproducible example at the moment.

Also, it's for sure there are no other database accesses running at the same time.

PS> Tried the READ-COMMITTED but it didn't help.
Actions
6. Re: I get a SQL error ONLY when running as a scheduled service?

karlnicholas Sep 5, 2016 3:15 PM (in response to karlnicholas)

Ok, problem solved.

I have a parent entity with 3 embedded collections of composite embedded keys to other entities. Embedded collections are always lazy loaded.

Since I was accessing the embedded collections after the parent entities became detached, I was using a query and then calling the 'setEmbeddedCollection(...) method of the parent entity to set the values of the collections. Perhaps if I was only doing a fetch there would be no problem, I don't know, I'll have to think about that. However, after doing this 'setEmbeddedCollection(...)' call I was then deleting the parent entity.

When running the code as a simple JPA application or even when starting the code with a JSF commandLink, the code would be using (I presume) an EntityTransaction. There was no problem. When running the code as a scheduled service, I needed to use the UserTransaction. The code (beans) are set to Bean Managed Transactions (BMT).

Under both transaction mangers the `setEmbeddedCollection(...)` would cause a database insert, effectively reinserting the rows that already existed. However, when running as a scheduled service, .i.e, under the UserTransaction, these inserts were delayed until the scheduled service had completed. By then the parent entity had been deleted and thus a foreign key constraint violation was caused. When running under the EntityTransaction, the inserts were done in the proper order and there was no problem.

The fix was to do the code correctly. My bad. Instead of doing selects and calling `setEmbeddedCollection` I simply reattached the parent entity before accessing those fields. This way lazy loading was handled by the EntityManger and no inserts were issued at all. Suffice it to say that the code's performance has increased by at least a factor of two.

It may be suggested that since I was using the embedded collection fields that I should have loaded then when I loaded the parent entities. However, I don't delete all of the parent entities and so I don't want to load all of those fields since I only look at them when I plan to delete the parent entity. By the time I've decided which entities to delete they have been detached. I'm thinking that I can only reattach them in a transaction, but like I said I'll have to think about that or play around with some sample code to figure that out.

I may be wrong about the EntityTransaction being used instead of the UserTransaction when executing the code from a JSF commandLink: I don't know because I didn't check specifically. However, something is different between running the code from a JSF commandLink and running the code as a scheduled service.

Thanks to all who offered suggestions.
Actions

Go to original post

	logger.info("STARTING SCRAPER UPDATE");
	caOnlineUpdates.updateDatabase(new TestCACaseScraper(false));
	logger.info("DONE SCRAPER UPDATE");