I believe we've always recommended that you SHOULD ONLY run one registry
cleaner per CAS install (or at least have one that can check if another one
is running, which we currently don't provide).  If that's not clear, we
should make it more clear in our documentation.   Considering they're on
relatively the same schedule if they're started at the same time, odds are
that one would execute while the other is executing.

The current registry cleaner will execute a delete when it determines that a
ticket is expired.  That logic is encapsulated into the TicketRegistry
itself.

-Scott

-Scott Battaglia
PGP Public Key Id: 0x383733AA
LinkedIn: http://www.linkedin.com/in/scottbattaglia


On Tue, Oct 28, 2008 at 7:34 PM, Andrew Bruno <[EMAIL PROTECTED]>wrote:

> As it turns out, because there are two (at the moment) CAS servers talking
> to one DB, the cleaner could cause a bit of chase situation, as you have
> higlighted, another process may be trying to update or delete the tickets.
>
> We have decided to completed remove the quartz/DefaultTicketRegistryCleaner
> cleaner from our CAS install and let the DB do the hard work, looking for
> expired tickets older (then our set time) and deleting them.  Its just a
> cleanup process, so this should be ok.
>
> We will be making the changes today, and will report if there are any
> problems over the next couple of days.
>
> Andrew
>
> P.S. Ideally a JPATicketRegistryCleaner class that executes a DELETE from
> table would be the best option for code completeness.
>
>
> On Wed, Oct 29, 2008 at 9:47 AM, Adam Rybicki <[EMAIL PROTECTED]> wrote:
>
>>  Andrew,
>>
>> This is an interesting discovery.  Apparently, the
>> DefaultTicketRegistryCleaner, as it's iterating through every ticket in the
>> database, attempted to delete a ticket whose state has in the meantime
>> changed (or was it deleted?)  My simple-minded initial reaction was to
>> change the transaction isolation level, but that could result in blocking
>> other ticket operations for excessively long time.
>>
>> Another approach would be to write a custom JpaTicketRegistryCleaner that
>> would cleverly, if at all possible, retrieve only expired tickets.  I don't
>> have enough spare cycles at the moment to consider the feasibility of such
>> an approach.
>>
>> This brings up another potential issue.  I think that every distributed
>> TicketRegistry implementation may be subject to this issue.  That is,
>> concurrent updates to a ticket from multiple threads or, more challengingly,
>> from multiple JVMs.  With DefaultTicketRegistry, this is nicely addressed by
>> using ConcurrentHashMap.  I could not tell what behavior other distributed
>> TicketRegistry implementations have.
>>
>> Perhaps Hibernate gives us a hint here: the optimistic locking feature
>> should be considered for all distributed TicketRegistry implementations.  If
>> the registry cleaner detects an update to stale data, the cleaner could
>> ignore this ticket and perhaps pick it up on the next pass.
>>
>> Adam
>>
>> Andrew Bruno wrote:
>>
>> And I also see these errors in logs
>>
>> ERROR 2008-10-27 04:53:44,833 [DefaultQuartzScheduler_Worker-8]
>> org.quartz.core.ErrorLogger - Job (DEFAULT.jobDetailTicketRegistryCleaner
>> threw an exception.
>>     org.quartz.SchedulerException: Job threw an unhandled exception. [See
>> nested exception:
>> org.springframework.scheduling.quartz.JobMethodInvocationFailedException:
>> Invocation of method 'clean' on target class [class $Proxy72] failed; nested
>> exception is
>> org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException:
>> Batch update returned unexpected row count from update [0]; actual row
>> count: 0; expected: 1; nested exception is
>> org.hibernate.StaleStateException: Batch update returned unexpected row
>> count from update [0]; actual row count: 0; expected: 1]
>>             at org.quartz.core.JobRunShell.run(JobRunShell.java:214)
>>             at
>> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
>>     * Nested Exception (Underlying Cause) ---------------
>>
>> org.springframework.scheduling.quartz.JobMethodInvocationFailedException:
>> Invocation of method 'clean' on target class [class $Proxy72] failed; nested
>> exception is
>> org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException:
>> Batch update returned unexpected row count from update [0]; actual row
>> count: 0; expected: 1; nested exception is
>> org.hibernate.StaleStateException: Batch update returned unexpected row
>> count from update [0]; actual row count: 0; expected: 1
>>             at
>> org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:269)
>>             at
>> org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
>>             at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>>             at
>> org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:520)
>>     Caused by:
>> org.springframework.orm.hibernate3.HibernateOptimisticLockingFailureException:
>> Batch update returned unexpected row count from update [0]; actual row
>> count: 0; expected: 1; nested exception is
>> org.hibernate.StaleStateException: Batch update returned unexpected row
>> count from update [0]; actual row count: 0; expected: 1
>>             at
>> org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:657)
>>             at
>> org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:95)
>>             at
>> org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:212)
>>             at
>> org.springframework.orm.jpa.JpaAccessor.translateIfNecessary(JpaAccessor.java:152)
>>             at
>> org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:189)
>>             at
>> org.springframework.orm.jpa.JpaTemplate.executeFind(JpaTemplate.java:151)
>>             at
>> org.springframework.orm.jpa.JpaTemplate.findByNamedParams(JpaTemplate.java:325)
>>             at
>> org.jasig.cas.ticket.registry.JpaTicketRegistry.deleteTicketAndChildren(JpaTicketRegistry.java:70)
>>             at
>> org.jasig.cas.ticket.registry.JpaTicketRegistry.deleteTicket(JpaTicketRegistry.java:63)
>>             at
>> org.jasig.cas.ticket.registry.support.DefaultTicketRegistryCleaner.clean(DefaultTicketRegistryCleaner.java:73)
>>             at sun.reflect.GeneratedMethodAccessor94.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:310)
>>             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 $Proxy72.clean(Unknown Source)
>>             at sun.reflect.GeneratedMethodAccessor92.invoke(Unknown
>> Source)
>>             at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>             at java.lang.reflect.Method.invoke(Method.java:597)
>>             at
>> org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:276)
>>             at
>> org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:260)
>>             ... 3 more
>>     Caused by: org.hibernate.StaleStateException: Batch update returned
>> unexpected row count from update [0]; actual row count: 0; expected: 1
>>             at
>> org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:61)
>>             at
>> org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:46)
>>             at
>> org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:24)
>>             at
>> org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2520)
>>             at
>> org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697)
>>             at
>> org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74)
>>             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:146)
>>             at
>> org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
>>             at
>> org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
>>             at
>> org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:969)
>>             at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1114)
>>             at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
>>             at
>> org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:66)
>>             at
>> org.springframework.orm.jpa.JpaTemplate$10.doInJpa(JpaTemplate.java:333)
>>             at
>> org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:184)
>>             ... 23 more
>>
>>
>>
>>
>> On Tue, Oct 28, 2008 at 1:50 PM, Andrew Bruno <[EMAIL PROTECTED]>wrote:
>>
>>> Hello all,
>>>
>>> We are using DB persistance for TicketGrantingTIcket table, and have
>>> managed to setup redundant load balanced servers successfully inc Single
>>> Sign Out.
>>>
>>> During load testing we noticed a few spikes every 83 minutes (5,000,000
>>> msecs) or so.
>>>
>>> It appears that this query is being executed
>>>
>>> select ticketgran0_.ID as ID2_, ticketgran0_.NUMBER_OF_TIMES_USED as
>>> NUMBER2_2_, ticketgran0_.CREATION_TIME as CREATION3_2_,
>>> ticketgran0_.EXPIRATION_POLICY as EXPIRATION4_2_,
>>> ticketgran0_.LAST_TIME_USED as LAST5_2_,
>>> ticketgran0_.PREVIOUS_LAST_TIME_USED as PREVIOUS6_2_,
>>> ticketgran0_.ticketGrantingTicket_ID as ticketG10_2_,
>>> ticketgran0_.AUTHENTICATION as AUTHENTI7_2_, ticketgran0_.EXPIRED as
>>> EXPIRED2_, ticketgran0_.SERVICES_GRANTED_ACCESS_TO as SERVICES9_2_ from
>>> TICKETGRANTINGTICKET ticketgran0_
>>>
>>> and there is no where clause.
>>>
>>> Looking through the code, I believe the culprit is
>>>
>>>
>>> https://www.ja-sig.org/svn/cas3/tags/cas-3-2-2-rc1/cas-server-core/src/main/java/org/jasig/cas/ticket/registry/support/DefaultTicketRegistryCleaner.java
>>>
>>> i.e. the clean method:
>>>
>>>         log
>>>             .info("Starting cleaning of expired tickets from ticket
>>> registry at ["
>>>                 + new Date() + "]");
>>>
>>> --> GETS ALL TICKETS (returned 1500 rows in one of our tests)
>>>
>>>         ticketsInCache = this.ticketRegistry.getTickets();
>>>
>>>         for (final Ticket ticket : ticketsInCache) {
>>>             if (ticket.isExpired()) {
>>>                 ticketsToRemove.add(ticket);
>>>             }
>>>         }
>>>
>>>         log.info(ticketsToRemove.size()
>>>             + " found to be removed.  Removing now.");
>>>
>>>         for (final Ticket ticket : ticketsToRemove) {
>>>             this.ticketRegistry.deleteTicket(ticket.getId());
>>>         }
>>>
>>>         log
>>>             .info("Finished cleaning of expired tickets from ticket
>>> registry at ["
>>>                 + new Date() + "]");
>>>
>>> Is there any reason why we need to get all the tickets, and the loop
>>> through them?
>>>
>>> If I was to write my own DB cleaner, how do I decide what the expiration
>>> policy is?
>>>
>>> Is there more to it that meets the eye?
>>>
>>> Many thanks
>>> Andrew
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>>>
>> ------------------------------
>>
>> _______________________________________________
>> Yale CAS mailing [EMAIL PROTECTED]://tp.its.yale.edu/mailman/listinfo/cas
>>
>>
>> _______________________________________________
>> Yale CAS mailing list
>> [email protected]
>> http://tp.its.yale.edu/mailman/listinfo/cas
>>
>>
>
> _______________________________________________
> Yale CAS mailing list
> [email protected]
> http://tp.its.yale.edu/mailman/listinfo/cas
>
>
_______________________________________________
Yale CAS mailing list
[email protected]
http://tp.its.yale.edu/mailman/listinfo/cas

Reply via email to