Uploaded image for project: 'Sakai'
  1. Sakai
  2. SAK-38454

Performance issues with message bundles loading and java.lang.IllegalStateException: Timer already cancelled. error

    XMLWordPrintable

    Details

    • Previous Issue Keys:
      KNL-875

      Description

      Jean-François Lévêque reported these issues. We've also experienced them.

      I first get this failure on the update :
      2011-09-15 09:07:27,269 ERROR Timer-3 org.hibernate.util.JDBCExceptionReporter - Lock wait timeout exceeded; try restarting transaction
      2011-09-15 09:07:27,270 ERROR Timer-3 org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
      org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
      at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
      at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
      at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
      at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:254)
      at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266)
      at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
      at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
      at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
      at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1001)
      at org.springframework.orm.hibernate3.HibernateAccessor.flushIfNecessary(HibernateAccessor.java:390)
      at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:420)
      at org.springframework.orm.hibernate3.HibernateTemplate.executeWithNativeSession(HibernateTemplate.java:374)
      at org.springframework.orm.hibernate3.HibernateTemplate.saveOrUpdate(HibernateTemplate.java:748)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl.updateMessageBundleProperty(MessageBundleServiceImpl.java:272)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl.saveOrUpdateInternal(MessageBundleServiceImpl.java:193)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl$SaveOrUpdateTask.run(MessageBundleServiceImpl.java:453)
      at java.util.TimerThread.mainLoop(Timer.java:512)
      at java.util.TimerThread.run(Timer.java:462)
      Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
      at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2024)
      at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1449)
      at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
      at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
      at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:247)
      ... 14 more
      Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
      at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3597)
      at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3529)
      at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
      at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
      at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
      at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119)
      at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415)
      at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1976)
      ... 18 more
      Exception in thread "Timer-3" org.springframework.dao.CannotAcquireLockException: Hibernate operation: Could not execute JDBC batch update; SQL [update SAKAI_MESSAGE_BUNDLE set MODULE_NAME=?, BASENAME=?, PROP_NAME=?, PROP_VALUE=?, LOCALE=?, DEFAULT_VALUE=? where ID=?]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
      at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:244)
      at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
      at org.springframework.orm.hibernate3.HibernateAccessor.convertJdbcAccessException(HibernateAccessor.java:424)
      at org.springframework.orm.hibernate3.HibernateAccessor.convertHibernateAccessException(HibernateAccessor.java:410)
      at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:424)
      at org.springframework.orm.hibernate3.HibernateTemplate.executeWithNativeSession(HibernateTemplate.java:374)
      at org.springframework.orm.hibernate3.HibernateTemplate.saveOrUpdate(HibernateTemplate.java:748)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl.updateMessageBundleProperty(MessageBundleServiceImpl.java:272)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl.saveOrUpdateInternal(MessageBundleServiceImpl.java:193)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl$SaveOrUpdateTask.run(MessageBundleServiceImpl.java:453)
      at java.util.TimerThread.mainLoop(Timer.java:512)
      at java.util.TimerThread.run(Timer.java:462)
      Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
      at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:2024)
      at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:1449)
      at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
      at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
      at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:247)
      at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266)
      at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168)
      at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
      at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
      at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1001)
      at org.springframework.orm.hibernate3.HibernateAccessor.flushIfNecessary(HibernateAccessor.java:390)
      at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:420)
      ... 7 more
      Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
      at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3597)
      at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3529)
      at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1990)
      at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
      at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
      at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2119)
      at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2415)
      at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1976)
      ... 18 more

      I then start to get ERRORs like :
      2011-09-15 09:09:25,326 ERROR TP-Processor24 org.sakaiproject.portal.util.ErrorReporter - Failed to generate request display
      java.lang.IllegalStateException: Timer already cancelled.
      at java.util.Timer.sched(Timer.java:354)
      at java.util.Timer.schedule(Timer.java:170)
      at org.sakaiproject.messagebundle.impl.MessageBundleServiceImpl.saveOrUpdate(MessageBundleServiceImpl.java:145)
      at sun.reflect.GeneratedMethodAccessor427.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
      at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
      at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
      at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
      at $Proxy135.saveOrUpdate(Unknown Source)
      at org.sakaiproject.util.DbResourceBundle.indexResourceBundle(DbResourceBundle.java:140)
      at org.sakaiproject.util.ResourceLoader.loadBundleFromDb(ResourceLoader.java:635)
      at org.sakaiproject.util.ResourceLoader.loadBundle(ResourceLoader.java:588)
      at org.sakaiproject.util.ResourceLoader.getBundleFromDb(ResourceLoader.java:556)
      at org.sakaiproject.util.ResourceLoader.getBundle(ResourceLoader.java:529)
      at org.sakaiproject.util.ResourceLoader.getString(ResourceLoader.java:370)
      at org.sakaiproject.portal.util.ErrorReporter.requestDisplay(ErrorReporter.java:596)
      at org.sakaiproject.portal.util.ErrorReporter.report(ErrorReporter.java:417)
      at org.sakaiproject.portal.util.ErrorReporter.report(ErrorReporter.java:399)
      at org.sakaiproject.portal.charon.SkinnableCharonPortal.doThrowableError(SkinnableCharonPortal.java:379)
      at org.sakaiproject.portal.charon.SkinnableCharonPortal.doGet(SkinnableCharonPortal.java:903)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:627)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
      at org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:659)
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:174)
      at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:200)
      at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
      at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:775)
      at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:704)
      at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:897)
      at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
      at java.lang.Thread.run(Thread.java:662)
      2011-09-15 09:09:25,337 ERROR TP-Processor24 org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/portal].[sakai.portal.charon] - "Servlet.service()" pour la servlet sakai.portal.charon a généré une exception

      And they keep coming until Tomcat is restarted.

      Cheers,

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                jbush John Bush
                Reporter:
                jbush John Bush
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Git Source Code