1 Reply Latest reply on Mar 27, 2009 11:50 AM by cecil dijoux

    [JBoss-4.0.3][SQLServer] LockAcquisitionException blocks the

    cecil dijoux Newbie

      Hello,

      Context :
      We are having a problem on the productive environment. We have an Enterprise Application deplioyed on JBoss-4.0.3 with Hibernate 3.2.3 and SQLServer 2005. We use sqljdbc driver version 1.1. We know there has been version 1.2 and 2.0 but the benchmark on our app is not so goood when we upgrade to these versions.

      Problem
      SQLServer sometimes identifies deadlock situations. This error is returned to Hibernate which throws a org.hibernate.exception.LockAcquisitionException.

      From this point onwards, the system no longer works : every single hibernate request to the DB server ends up in error. We have dozens of following exception :

      PDM:1.4.7.6 - jboss - mssql - 7776828 [http-0.0.0.0-8080-10] ERROR com.lectra.pdm.applicationserver.pub.commands.CommandBuilder - CommandBuilder - execute : com.lectra.pdm.enterpriselayer.pub.cbr.CustomBusinessRuleException: Not traduct[[class com.lectra.pdm.enterpriselayer.server.persistencymanagement.exceptions.PersistencyException : org.hibernate.exception.SQLGrammarException: could not get or update next value]]
      INFO | jvm 1 | 2009/03/24 17:25:42 | PDM:1.4.7.6 - jboss - mssql - 7792578 [http-0.0.0.0-8080-9] INFO org.jboss.resource.connectionmanager.CachedConnectionManager - Closing a connection for you. Please close them yourself: org.jboss.resource.adapter.jdbc.WrappedConnection@879a32
      INFO | jvm 1 | 2009/03/24 17:25:42 | java.lang.Throwable: STACKTRACE
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.resource.connectionmanager.CachedConnectionManager.registerConnection(CachedConnectionManager.java:333)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:482)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:894)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:73)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:69)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:421)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1538)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.doQuery(Loader.java:661)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.loadEntity(Loader.java:1851)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.entity.BatchingEntityLoader.load(BatchingEntityLoader.java:82)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3038)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:195)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.impl.SessionImpl.internalLoad(SessionImpl.java:846)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:557)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.type.ManyToOneType.assemble(ManyToOneType.java:196)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.cache.StandardQueryCache.get(StandardQueryCache.java:130)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.getResultFromQueryCache(Loader.java:2152)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2117)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.Loader.list(Loader.java:2087)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:375)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:811)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.persistencymanagement.PersistencyManager.findSessionBySessionId(PersistencyManager.java:671)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.sessionmanagement.SessionManager.isSessionValid(SessionManager.java:127)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.utils.SessionUtils.checkSession(SessionUtils.java:25)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.contentmanagement.ContentManager.readContent(ContentManager.java:299)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.contentmanagement.ejb.ContentManagementFacadeBean.readContent(ContentManagementFacadeBean.java:502)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at sun.reflect.GeneratedMethodAccessor1844.invoke(Unknown Source)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at java.lang.reflect.Method.invoke(Method.java:585)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:214)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:154)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.webservice.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:54)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:48)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.Container.invoke(Container.java:873)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:415)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:88)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at $Proxy176.readContent(Unknown Source)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at com.lectra.pdm.enterpriselayer.server.contentmanagement.servlet.ContentAccessServlet.doGet(ContentAccessServlet.java:712)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at javax.servlet.http.HttpServlet.service(HttpServlet.java:697)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:81)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.web.tomcat.security.CustomPrincipalValve.invoke(CustomPrincipalValve.java:39)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:159)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:59)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:856)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:744)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
      INFO | jvm 1 | 2009/03/24 17:25:42 | at java.lang.Thread.run(Thread.java:595)
      
      


      Solution :
      The solution we have found to fix this : stop and restart the jboss.jca:Service=ManagedConnectionPool. Obviously this is just not acceptable iun a productive environment.

      We have changed the SQLServer configuration to set Snapshot mode and Read_Commited mode. We still have this LockAcquisition exception that brings our ManagedConnectionPool down and stop our application from being used.

      Has anybody seen this problem ? Can you propose a solution ? What would you recommend ? Thnaks !