[JBoss-4.0.3][SQLServer] LockAcquisitionException blocks the
ceciiil Mar 24, 2009 1:36 PMHello,
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 !