Jasper Reports upgrade 7.2 to 7.5: Internal cron job ERRORS now

[brodie]

Greetings!   I just upgraded a jasperreports server from 7.2 to 7.5.    The database is mysql.

I now see these errors on an hourly basis, generated from the internal job scheduler.

Any help is appreciated!

2020-02-14T10:00:00,003 ERROR ErrorLogger,JasperServerMaintenanceScheduler_Worker-2:2407 - Job (DEFAULT.accessEventPurgerJob threw an exception. org.quartz.SchedulerException: Job threw an unhandled exception. [see nested exception: com.jaspersoft.jasperserver.api.engine.scheduling.quartz.JSJobMethodInvocationFailedException: Invocation of method 'purgeAccessEvents' on target class [class com.sun.proxy.$Proxy80] failed; nested exception is org.springframework.orm.hibernate5.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [n/a]; SQL state [HY000]; error code [1093]; could not execute statement; nested exception is org.hibernate.exception.GenericJDBCException: could not execute statement]
    at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
    at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: com.jaspersoft.jasperserver.api.engine.scheduling.quartz.JSJobMethodInvocationFailedException: Invocation of method 'purgeAccessEvents' on target class [class com.sun.proxy.$Proxy80] failed; nested exception is org.springframework.orm.hibernate5.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [n/a]; SQL state [HY000]; error code [1093]; could not execute statement; nested exception is org.hibernate.exception.GenericJDBCException: could not execute statement
    at com.jaspersoft.jasperserver.api.engine.scheduling.quartz.JSMethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(JSMethodInvokingJobDetailFactoryBean.java:254)
    at com.jaspersoft.jasperserver.api.engine.scheduling.quartz.JSQuartzJobBean.execute(JSQuartzJobBean.java:51)
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
    ... 1 more
Caused by: org.springframework.orm.hibernate5.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [n/a]; SQL state [HY000]; error code [1093]; could not execute statement; nested exception is org.hibernate.exception.GenericJDBCException: could not execute statement
    at org.springframework.orm.hibernate5.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:248)
    at org.springframework.orm.hibernate5.HibernateTemplate.doExecute(HibernateTemplate.java:364)
    at org.springframework.orm.hibernate5.HibernateTemplate.executeWithNativeSession(HibernateTemplate.java:328)
    at org.springframework.orm.hibernate5.HibernateTemplate.bulkUpdate(HibernateTemplate.java:1133)
    at com.jaspersoft.jasperserver.api.logging.access.service.impl.AccessServiceImpl.purgeAccessEvents(AccessServiceImpl.java:186)
    at sun.reflect.GeneratedMethodAccessor398.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
    at com.sun.proxy.$Proxy80.purgeAccessEvents(Unknown Source)
    at sun.reflect.GeneratedMethodAccessor397.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:265)
    at com.jaspersoft.jasperserver.api.engine.scheduling.quartz.JSMethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(JSMethodInvokingJobDetailFactoryBean.java:247)
    ... 3 more
Caused by: org.hibernate.exception.GenericJDBCException: could not execute statement
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178)
    at org.hibernate.hql.internal.ast.exec.BasicExecutor.doExecute(BasicExecutor.java:100)
    at org.hibernate.hql.internal.ast.exec.BasicExecutor.execute(BasicExecutor.java:59)
    at org.hibernate.hql.internal.ast.exec.DeleteExecutor.execute(DeleteExecutor.java:110)
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:442)
    at org.hibernate.engine.query.spi.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:374)
    at org.hibernate.internal.SessionImpl.executeUpdate(SessionImpl.java:1512)
    at org.hibernate.query.internal.AbstractProducedQuery.doExecuteUpdate(AbstractProducedQuery.java:1526)
    at org.hibernate.query.internal.AbstractProducedQuery.executeUpdate(AbstractProducedQuery.java:1504)
    at org.springframework.orm.hibernate5.HibernateTemplate$38.doInHibernate(HibernateTemplate.java:1145)
    at org.springframework.orm.hibernate5.HibernateTemplate$38.doInHibernate(HibernateTemplate.java:1133)
    at org.springframework.orm.hibernate5.HibernateTemplate.doExecute(HibernateTemplate.java:361)
    ... 23 more
Caused by: java.sql.SQLException: (conn:637785) You can't specify target table 'JIAccessEvent' for update in FROM clause
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:179)
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:118)
    at org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:247)
    at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:218)
    at org.mariadb.jdbc.MariaDbPreparedStatementClient.execute(MariaDbPreparedStatementClient.java:153)
    at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeUpdate(MariaDbPreparedStatementClient.java:186)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
    at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
    ... 34 more
Caused by: java.sql.SQLException: You can't specify target table 'JIAccessEvent' for update in FROM clause
Query is: delete from JIAccessEvent where id in (select repoaccess1_.id from JIAccessEvent repoaccess1_ left outer join JIResource reporesour3_ on repoaccess1_.resource_id=reporesour3_.id left outer join JIUser repouser5_ on repoaccess1_.user_id=repouser5_.id left outer join JIResource reporesour2_ on (reporesour2_.id=repoaccess1_.resource_id) left outer join JIUser repouser4_ on (repouser4_.id=repoaccess1_.user_id) where reporesour2_.id is null or repouser4_.id is null)
    at org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:145)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:222)
    at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeInternal(MariaDbPreparedStatementClient.java:212)
    ... 39 more

 

[lgeorge]

seeing the same on a 7.5 fresh install. any luck resolving?

[andy.savin]

I contacted Tibco and apparently this issue has been rasied as a defect.

 

[narendrapothuganti7]

Even I am facing the same issue in fresh install of JRS 7.5.0. Is this issue resolved?

Can someone give any update on this?

[patds]

We are in the same situation with version 7.8.0. Anyone could get any solution/workaround for this?

[andy.savin]

I've been told that, the devs don't see this as a critical issue to fix however, a number of people have raised it so maybe they'll fix it in a future release.  Apparently, there is no major impact on the system other than having an anoying stacktrace fulling up the logs.  I guess you could lower the log level fot that particular class to avoud seeing it.

[robert.bellemare]

No major impact is incorrect. There is a significant performance issue that will develop over time of 15+ second of wastage per report execution.

When you get to a sufficient level of object access history, you will see 03wb337htj9ht SQL (select count(id) from JIAccessEvent where resource_id =:1) taking several seconds of waste during each report execution. This SQL is being called by 

com.jaspersoft.jasperserver.api.metadata.common.service.impl.hibernate.persistent.RepoFileResource:$$_hibernate_clearDirtyCollectionNames

This sql takes 10-350 ms to execute, and a sample report we run in our software will generate 169 calls to this SQL. I think you can do the math. We are running a three node Oracle exadata RAC, it's not a question of resource starvation.