Uploaded image for project: 'JCommune'
  1. JCommune
  2. JC-1742

LockAquisitionException when creating topic

VotersWatchers
    XMLWordPrintable

    Details

    • Sprint:
      2.5 Larks, 2.10 Larks, 2.12 Larks, 2.13 Larks, 2.14 Larks

      Description

      From time to time during autotests we get error 500 when user creates a topic. In logs we see:

      2014-01-18 01:06:04 [DEBUG][http-4080-5     ][admin][org.jtalks.jcommune.web.exception.PrettyLogExceptionResolver] - Resolving exception from handler [public org.springframework.
      web.servlet.ModelAndView org.jtalks.jcommune.web.controller.TopicController.createTopic(org.jtalks.jcommune.web.dto.TopicDto,org.springframework.validation.BindingResult,java.lan
      g.Long) throws org.jtalks.jcommune.service.exceptions.NotFoundException]: org.springframework.dao.CannotAcquireLockException: could not update: [org.jtalks.jcommune.model.entity.
      JCUser#1]; SQL [update USERS set VERSION=?, UUID=?, FIRST_NAME=?, LAST_NAME=?, USERNAME=?, ENCODED_USERNAME=?, EMAIL=?, PASSWORD=?, LAST_LOGIN=?, AVATAR=?, ENABLED=? where ID=? a
      nd VERSION=?]; nested exception is org.hibernate.exception.LockAcquisitionException: could not update: [org.jtalks.jcommune.model.entity.JCUser#1]
      2014-01-18 01:06:04 [WARN ][http-4080-5     ][admin][                 org.jtalks.jcommune] - Handler execution resulted in exception
      org.springframework.dao.CannotAcquireLockException: could not update: [org.jtalks.jcommune.model.entity.JCUser#1]; SQL [update USERS set VERSION=?, UUID=?, FIRST_NAME=?, LAST_NAM
      E=?, USERNAME=?, ENCODED_USERNAME=?, EMAIL=?, PASSWORD=?, LAST_LOGIN=?, AVATAR=?, ENABLED=? where ID=? and VERSION=?]; nested exception is org.hibernate.exception.LockAcquisition
      Exception: could not update: [org.jtalks.jcommune.model.entity.JCUser#1]
              at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:639)
              at org.springframework.orm.hibernate3.HibernateExceptionTranslator.convertHibernateAccessException(HibernateExceptionTranslator.java:89)
              at org.springframework.orm.hibernate3.HibernateExceptionTranslator.translateExceptionIfPossible(HibernateExceptionTranslator.java:68)
              at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:58)
              at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:213)
              at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:163)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
              at com.sun.proxy.$Proxy64.saveOrUpdate(Unknown Source)
              at org.jtalks.jcommune.service.transactional.TransactionalTopicModificationService.createTopic(TransactionalTopicModificationService.java:171)
              at sun.reflect.GeneratedMethodAccessor487.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:606)
              at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
              at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:67)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at etm.contrib.aop.aopalliance.EtmMethodCallInterceptor.invoke(EtmMethodCallInterceptor.java:62)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
              at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
              at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
              at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
              at com.sun.proxy.$Proxy92.createTopic(Unknown Source)
              at org.jtalks.jcommune.web.controller.TopicController.createTopicWithLockHandling(TopicController.java:176)
              at org.jtalks.jcommune.web.controller.TopicController.createTopic(TopicController.java:167)
              at sun.reflect.GeneratedMethodAccessor482.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:606)
              at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219)
              at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
              at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
              at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745)
              at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686)
              at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
              at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
              at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
              at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936)
              at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:838)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
              at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.jtalks.jcommune.web.filters.HeadRequestTypeFilter.doFilter(HeadRequestTypeFilter.java:45)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.jtalks.jcommune.web.filters.LoggingConfigurationFilter.doFilter(LoggingConfigurationFilter.java:69)
              at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
              at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
              at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:368)
              at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
              at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:97)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:100)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:78)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:119)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:35)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:177)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:187)
              at org.jtalks.jcommune.web.filters.UsernamePasswordAuthenticationFilter.doFilter(UsernamePasswordAuthenticationFilter.java:63)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:79)
              at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:380)
              at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:169)
              at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
              at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.orm.hibernate3.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:233)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at com.cj.trim.trimFilter.doFilter(Unknown Source)
              at org.jtalks.jcommune.web.filters.TrimFilter.doFilter(TrimFilter.java:82)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
              at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
              at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
              at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
              at java.lang.Thread.run(Thread.java:724)
      Caused by: org.hibernate.exception.LockAcquisitionException: could not update: [org.jtalks.jcommune.model.entity.JCUser#1]
              at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:107)
              at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
              at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2612)
              at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2494)
              at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2821)
              at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:113)
              at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:273)
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:265)
              at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:185)
              at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
              at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51)
              at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1216)
              at org.jtalks.common.model.dao.hibernate.GenericDao.saveOrUpdate(GenericDao.java:77)
              at sun.reflect.GeneratedMethodAccessor364.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:606)
              at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
              at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:155)
              ... 114 more
      Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
              at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
              at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
              at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
              at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
              at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
              at com.mysql.jdbc.Util.getInstance(Util.java:386)
              at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1066)
              at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4187)
              at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4119)
              at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570)
              at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)
              at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2815)
              at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155)
              at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458)
              at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375)
              at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359)
              at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105)
              at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2594)
              ... 131 more
      2014-01-18 01:06:04 [INFO ][http-4080-5     ][admin][org.jtalks.jcommune.web.exception.PrettyLogExceptionResolver] - [POST][http://autotests.jtalks.org/jcommune/topics/new?branchId=4][JSESSIONID=65BC2C9EA7F994A75D631A936C8BE817; SPRING_SECURITY_REMEMBER_ME_COOKIE=K3JtSm9LeE8xSEJ2VldBMWdzdUNlUT09OkEybmpVN0szOCtkOWFZdlJlMFpjSmc9PQ; org.springframework.web.servlet.i18n.CookieLocaleResolver.LOCALE=en; GMT=0][]
      2014-01-18 01:06:04 [DEBUG][http-4080-5     ][admin][org.jtalks.jcommune.web.exception.PrettyLogExceptionResolver] - Resolving to default view 'redirect:/errors/500' for exception of type [org.springframework.dao.CannotAcquireLockException]
      2014-01-18 01:06:04 [DEBUG][http-4080-5     ][admin][org.jtalks.jcommune.web.exception.PrettyLogExceptionResolver] - Exposing Exception as model attribute 'exception'
      

        Attachments

        1. didnt_occured.mysql.log
          19 kB
          Mikhail Stryzhonak
        2. innodb-deadlock.txt
          11 kB
          Guram Savinov
        3. jcommune.create-topic.jmx
          23 kB
          Guram Savinov
        4. occured.mysql.log
          4 kB
          Mikhail Stryzhonak

          Issue Links

            Structure

              Activity

                People

                • Assignee:
                  Unassigned
                  Reporter:
                  ctapobep Stanislav Bashkyrtsev
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  4 Start watching this issue

                  Dates

                  • Created:
                    Updated:

                    Time Tracking

                    Estimated:
                    Original Estimate - 0h
                    0h
                    Remaining:
                    Remaining Estimate - 0h
                    0h
                    Logged:
                    Time Spent - 2h
                    2h

                      Structure Helper Panel