[
https://issues.apache.org/jira/browse/SYNCOPE-1244?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Francesco Chicchiriccò reopened SYNCOPE-1244:
---------------------------------------------
The changes for this issue make the test case
{{MultitenancyITCase#createResourceAndPull}} fail with exception:
{{code}}
ERROR org.apache.syncope.core.logic.AbstractLogic - While registering quartz
job for task 1d9deccf-1fc5-431f-9dec-cf1fc5e31f2b
org.quartz.impl.jdbcjobstore.LockException: Failure obtaining db row lock:
Connection is closed
at
org.quartz.impl.jdbcjobstore.StdRowLockSemaphore.executeSQL(StdRowLockSemaphore.java:157)
~[quartz-2.3.0.jar:?]
at
org.quartz.impl.jdbcjobstore.DBSemaphore.obtainLock(DBSemaphore.java:113)
~[quartz-2.3.0.jar:?]
at
org.quartz.impl.jdbcjobstore.JobStoreCMT.executeInLock(JobStoreCMT.java:238)
~[quartz-2.3.0.jar:?]
at
org.quartz.impl.jdbcjobstore.JobStoreSupport.storeJob(JobStoreSupport.java:1091)
~[quartz-2.3.0.jar:?]
at org.quartz.core.QuartzScheduler.addJob(QuartzScheduler.java:938)
~[quartz-2.3.0.jar:?]
at org.quartz.core.QuartzScheduler.addJob(QuartzScheduler.java:927)
~[quartz-2.3.0.jar:?]
at org.quartz.impl.StdScheduler.addJob(StdScheduler.java:268)
~[quartz-2.3.0.jar:?]
at
org.apache.syncope.core.provisioning.java.job.JobManagerImpl.registerJob(JobManagerImpl.java:171)
~[syncope-core-provisioning-java-2.0.7-SNAPSHOT.jar:2.0.7-SNA
PSHOT]
at
org.apache.syncope.core.provisioning.java.job.JobManagerImpl.register(JobManagerImpl.java:244)
~[syncope-core-provisioning-java-2.0.7-SNAPSHOT.jar:2.0.7-SNAPSH
OT]
at
org.apache.syncope.core.logic.TaskLogic.createSchedTask(TaskLogic.java:106)
~[syncope-core-logic-2.0.7-SNAPSHOT.jar:2.0.7-SNAPSHOT]
{{code}}
> Error creating bean with name 'logicInitializer' on startup related to quartz
> clustering
> -----------------------------------------------------------------------------------------
>
> Key: SYNCOPE-1244
> URL: https://issues.apache.org/jira/browse/SYNCOPE-1244
> Project: Syncope
> Issue Type: Bug
> Components: core
> Affects Versions: 2.0.2
> Reporter: gonzalad
> Assignee: Francesco Chicchiriccò
> Fix For: 2.0.7, 2.1.0
>
> Attachments: SYNCOPE-1244-2.diff, SYNCOPE-1244-3.diff,
> SYNCOPE-1244-4.diff, SYNCOPE-1244-5.diff, SYNCOPE-1244.diff, TPSVC-3882.zip
>
>
> I use syncope 2.0.2 in high availability mode (4 instances).
> I'm using syncope with postgresql db.
> Sometimes on startup I have the following error, and the instance fails to
> start:
> {code}
> 17-12-03 18:39:10.781 ERROR - [syncope] - [localhost-startStop-5]
> org.springframework.web.context.ContextLoader - Context initialization failed
> org.springframework.beans.factory.BeanCreationException: Error creating bean
> with name 'logicInitializer' defined in URL
> [jar:file:/usr/local/tomcat/webapps/syncope/WEB-INF/lib/syncope-core-logic-2.0.2_1.jar!/org/apache/syncope/core/logic/init/LogicInitializer.class]:
> Invocation of init method failed; nested exception is
> <openjpa-2.4.2-r422266:1777108 fatal general error>
> org.apache.openjpa.persistence.PersistenceException: ERROR: current
> transaction is aborted, commands ignored until end of transaction block
> {prepstmnt 977966121 SELECT t0.id, t0.active, t0.cronExpression, t0.name,
> t1.id, t1.csvTemplate, t1.foTemplate, t1.htmlTemplate FROM Report t0 INNER
> JOIN ReportTemplate t1 ON t0.template_id = t1.id} [code=0, state=25P02]
> FailedObject: SELECT e FROM JPAReport e [java.lang.String]
> at
> org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1628)
> ~[spring-beans-4.3.6.RELEASE.jar:4.3.6.RELEASE]
> at
> org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:555)
> ~[spring-beans-4.3.6.RELEASE.jar:4.3.6.RELEASE]
> at
> org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
> ~[
> Caused by: org.apache.openjpa.persistence.PersistenceException: ERROR:
> current transaction is aborted, commands ignored until end of transaction
> block {prepstmnt 977966121 SELECT t0.id, t0.active, t0.cronExpression,
> t0.name, t1.id, t1.csvTemplate, t1.foTemplate, t1.htmlTemplate FROM Report t0
> INNER JOIN ReportTemplate t1 ON t0.template_id = t1.id} [code=0, state=25P02]
> at
> org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:5003)
> ~[openjpa-jdbc-2.4.2.jar:2.4.2]
> ...
> at
> org.apache.openjpa.persistence.QueryImpl.getResultList(QueryImpl.java:290)
> ~[openjpa-persistence-2.4.2.jar:2.4.2]
> at
> org.apache.syncope.core.persistence.jpa.dao.JPAReportDAO.findAll(JPAReportDAO.java:55)
> ~[syncope-core-persistence-jpa-2.0.2_1.jar:2.0.2_1]
> ...
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
> ~[spring-aop-4.3.6.RELEASE.jar:4.3.6.RELEASE]
> at com.sun.proxy.$Proxy427.findAll(Unknown Source) ~[?:?]
> at
> org.apache.syncope.core.logic.init.JobManagerImpl$3.exec(JobManagerImpl.java:327)
> ~[syncope-core-logic-2.0.2_1.jar:2.0.2_1]
> at
> org.apache.syncope.core.logic.init.JobManagerImpl$3.exec(JobManagerImpl.java:310)
> ~[syncope-core-logic-2.0.2_1.jar:2.0.2_1]
> at
> org.apache.syncope.core.spring.security.AuthContextUtils.execWithAuthContext(AuthContextUtils.java:114)
> ~[syncope-core-spring-2.0.2_1.jar:2.0.2_1]
> at
> org.apache.syncope.core.logic.init.JobManagerImpl.load(JobManagerImpl.java:310)
> ~[syncope-core-logic-2.0.2_1.jar:2.0.2_1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> ~[?:1.8.0_131]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> ~[?:1.8.0_131]
> ...
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
> ~[spring-aop-4.3.6.RELEASE.jar:4.3.6.RELEASE]
> at com.sun.proxy.$Proxy428.load(Unknown Source) ~[?:?]
> at
> org.apache.syncope.core.logic.init.LogicInitializer.afterPropertiesSet(LogicInitializer.java:70)
> ~[syncope-core-logic-2.0.2_1.jar:2.0.2_1]
> Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: ERROR: current
> transaction is aborted, commands ignored until end of transaction block
> {prepstmnt 977966121 SELECT t0.id, t0.active, t0.cronExpression, t0.name,
> t1.id, t1.csvTemplate, t1.foTemplate, t1.htmlTemplate FROM Report t0 INNER
> JOIN ReportTemplate t1 ON t0.template_id = t1.id} [code=0, state=25P02]
> ...
> at org.apache.openjpa.persistence.QueryImpl.execute(QueryImpl.java:274)
> ~[openjpa-persistence-2.4.2.jar:2.4.2]
> at
> org.apache.openjpa.persistence.QueryImpl.getResultList(QueryImpl.java:290)
> ~[openjpa-persistence-2.4.2.jar:2.4.2]
> at
> org.apache.syncope.core.persistence.jpa.dao.JPAReportDAO.findAll(JPAReportDAO.java:55)
> ~[syncope-core-persistence-jpa-2.0.2_1.jar:2.0.2_1]
> ...
> at
> org.apache.syncope.core.logic.init.JobManagerImpl$3.exec(JobManagerImpl.java:327)
> ~[syncope-core-logic-2.0.2_1.jar:2.0.2_1]
> {code}
> From what I understand, this happens when one instance already holds the
> quartz lock, hence the other instance tries to grasp it and fails with a
> LockException.
> The JobManagerImpl executes this kind of code
> https://github.com/apache/syncope/blob/cea47da1a1510446b7bd62fbc8e45cc8757d6611/core/provisioning-java/src/main/java/org/apache/syncope/core/provisioning/java/job/JobManagerImpl.java#L326-L351
> :
> {code}
> // 1. jobs for SchedTasks
> Set<SchedTask> tasks = new
> HashSet<>(taskDAO.<SchedTask>findAll(TaskType.SCHEDULED));
> tasks.addAll(taskDAO.<PullTask>findAll(TaskType.PULL));
> tasks.addAll(taskDAO.<PushTask>findAll(TaskType.PUSH));
> for (SchedTask task : tasks) {
> try {
> register(task, task.getStartAt(),
> conf.getRight());
> } catch (Exception e) {
> LOG.error("While loading job instance for task "
> + task.getKey(), e);
> }
> }
> // 2. jobs for Reports
> for (Report report : reportDAO.findAll()) {
> try {
> register(report, null, conf.getRight());
> } catch (Exception e) {
> LOG.error("While loading job instance for report
> " + report.getName(), e);
> }
> }
> {code}
> The LockException happens during the first call to register.
> The exception is caught.
> Problem is in the logged stackTrace I see:
> {code}
> 17-12-03 18:39:06.659 ERROR - [syncope] - [localhost-startStop-5]
> org.apache.syncope.core.provisioning.api.job.JobManager - Could not remove
> job taskJobe84fd2bc-e472-48a1-8fd2-bce472c8a1ba
> org.quartz.impl.jdbcjobstore.LockException: Failure obtaining db row lock:
> ERROR: current transaction is aborted, commands ignored until end of
> transaction block {prepstmnt 1348492786 SELECT * FROM QRTZ_LOCKS WHERE
> SCHED_NAME = 'scheduler' AND LOCK_NAME = ? FOR UPDATE} [code=0, state=25P02]
> {code}
> Postgres says `commands ignored until end of transaction block`.
> And the real exception happens when we call reportDAO.findAll(), with
> {code}
> Caused by: <openjpa-2.4.2-r422266:1777108 fatal general error>
> org.apache.openjpa.persistence.PersistenceException: ERROR: current
> transaction is aborted, commands ignored until end of transaction block
> {prepstmnt 977966121 SELECT t0.id, t0.active, t0.cronExpression, t0.name,
> t1.id, t1.csvTemplate, t1.foTemplate, t1.htmlTemplate FROM Report t0 INNER
> JOIN ReportTemplate t1 ON t0.template_id = t1.id} [code=0, state=25P02]
> FailedObject: SELECT e FROM JPAReport e [java.lang.String]
> {code}
> So postgresql seems to fulfill its promise and raise an error on any
> subsequent SQL statement issued under the same transaction context.
> Perhaps, we need either :
> * to start a new transaction on each call to register.
> * to stop the jobManagerImpl.load method execution on the first error.
> I don't know if that would be enough (i.e. what happend when the
> TransactionInterceptor surrounding JobManagerImpl executes - would it throw
> an error ?)
>
> I'll attach the full logs (the interesting part starts at line 4405).
> Thanks,
> Adrian
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
