We are getting some deadlocking issues with cas 3.3.5 (JPA ticket registry)
and uportal 3.1.2...both are using SQL Server 2005 for the database. We are
running two instances of cas and two instances of uportal (each on their own
server) and are performing load balancing with apache mod proxy.
CAS starts throwing some deadlock errors when we put some stress on it. When
we experience deadlocks we seem to be getting the following errors on both
the cas and uportal sides
Errors from cas
[ERROR] 2010-06-02 16:32:21,374
org.hibernate.util.JDBCExceptionReporter:78
Transaction (Process ID 98) was deadlocked on lock resources with another
process and has been chosen as the deadlock victim. Rerun the transaction.
[ERROR] 2010-06-02 16:32:22,346
org.hibernate.event.def.AbstractFlushingEventListener:301
Could not synchronize database state with session
org.hibernate.exception.LockAcquisitionException: could not update:
[org.jasig.cas.ticket.ServiceTicketImpl#ST-3473-T9gQxYIowISnkg1FlSU9-cas1tomcatjvm1]
at
org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:82)
at
org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at
org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2425)
at
org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2307)
at
org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2607)
at
org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250)
at
org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234)
at
org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:142)
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:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at
org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54)
at
org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:456)
at
org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
at
org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
at
org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
at
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at $Proxy25.delegateTicketGrantingTicket(Unknown Source)
at
org.jasig.cas.web.ServiceValidateController.handleRequestInternal(ServiceValidateController.java:126)
at
org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
at
org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:807)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
at
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at
org.jasig.cas.web.init.SafeDispatcherServlet.service(SafeDispatcherServlet.java:115)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.inspektr.common.web.ClientInfoThreadLocalFilter.doFilterInternal(ClientInfoThreadLocalFilter.java:48)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
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.ajp.AjpAprProcessor.process(AjpAprProcessor.java:427)
at
org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:384)
at
org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1555)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.sql.SQLException: Transaction (Process ID 98) was deadlocked
on lock resources with another process and has been chosen as the deadlock
victim. Rerun the transaction.
at
net.sourceforge.jtds.jdbc.SQLDiagnostic.addDiagnostic(SQLDiagnostic.java:368)
at
net.sourceforge.jtds.jdbc.TdsCore.tdsErrorToken(TdsCore.java:2816)
at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2254)
at
net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:631)
at
net.sourceforge.jtds.jdbc.JtdsStatement.processResults(JtdsStatement.java:584)
at
net.sourceforge.jtds.jdbc.JtdsStatement.executeSQL(JtdsStatement.java:546)
at
net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeUpdate(JtdsPreparedStatement.java:505)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:102)
at
org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:23)
at
org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2403)
... 46 more
Errors from uportal
[ERROR] 2010-06-02 16:32:21,556
edu.yale.its.tp.cas.client.CASReceipt:57
edu.yale.its.tp.cas.client.CASAuthenticationException: Unable to validate
ProxyTicketValidator [[edu.yale.its.tp.cas.client.ProxyTicketValidator
proxyList=[null] [edu.yale.its.tp.cas.client.ServiceTicketValidator
casValidateUrl=[https://cas.heartland.edu/cas/serviceValidate]
proxyCallbackUrl=[https://my.heartland.edu/CasProxyServlet]
ticket=[ST-3473-T9gQxYIowISnkg1FlSU9-cas1tomcatjvm1] service=[https%3A%2F%
2Fmy.heartland.edu%2FLogin] renew=false]]]
[ERROR] 2010-06-02 16:32:22,952
edu.yale.its.tp.cas.client.filter.CASValidateFilter:344
edu.yale.its.tp.cas.client.CASAuthenticationException: Unable to validate
ProxyTicketValidator [[edu.yale.its.tp.cas.client.ProxyTicketValidator
proxyList=[null] [edu.yale.its.tp.cas.client.ServiceTicketValidator
casValidateUrl=[https://cas.heartland.edu/cas/serviceValidate]
proxyCallbackUrl=[https://my.heartland.edu/CasProxyServlet]
ticket=[ST-3473-T9gQxYIowISnkg1FlSU9-cas1tomcatjvm1] service=[https%3A%2F%
2Fmy.heartland.edu%2FLogin] renew=false]]]
Some thoughts and questions
1) Took Unicon's advise about SQL Server and enabled the
ALLOW_SNAPSHOT_ISOLATION and READ_COMMITTED_SNAPSHOT (
http://www.unicon.net/node/1076). This seems to be working for uportal. We
tried the same options on the cas database but didn't notice any
difference...could hibernate be undoing something?
2) We thought the ticket cleaners may be bumping into each other so we shut
down one cas jvm and routed all traffic to the other...this didn't seem to
matter.
3) On the last cas community call, Marvin mentioned that the deadlocks were
probably the result of not having some indexes (
https://wiki.jasig.org/display/CASUM/JpaTicketRegistry). We added the
suggested indexes and didn't see much of a difference
4) We are running cas-server-3.3.5 and uportal is using
casclient-2.2.0-M3.jar (the original configured client)...are these
compatible with each other or should does the client need to be updated? We
are also getting a number of the following errors that resemble an issues
reported at
https://issues.jasig.org/browse/CASC-89%3bjsessionid=6D6067DE763D1663E3066F87B870E309.cas?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel...I'm
guessing maybe this is totally unrelated to the deadlocking but we
are unsure why we are getting this as well.
[ERROR] 2010-06-02 15:39:01,435
org.jasig.cas.util.HttpClient:214
java.net.ProtocolException: Server redirected too many times (20)
java.net.ProtocolException: Server redirected too many times (20)
at
sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1323)
at
sun.net.www.protocol.https.HttpsURLConnectionImpl.getInputStream(HttpsURLConnectionImpl.java:234)
at
org.jasig.cas.util.HttpClient$MessageSender.call(HttpClient.java:200)
at
org.jasig.cas.util.HttpClient$MessageSender.call(HttpClient.java:160)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
--
Curtis Garman
--
You are currently subscribed to [email protected] as:
[email protected]
To unsubscribe, change settings or access archives, see
http://www.ja-sig.org/wiki/display/JSG/cas-user
