CAS 5.2.2-snapshot identifies expired TGTs and erroneously reports they are deleted.

66 views
Skip to first unread message

Maxwell, Gary

unread,
Feb 16, 2018, 5:08:24 PM2/16/18
to cas-...@apereo.org

We are still experiencing a problem with the expiration of TGT's  Ehache. The “timeToKillInSeconds” value seems to have no effect on removing the TGT from Ehcache temp folder. The TGT entries are not deleted until the “maxTimeToLiveInSeconds” is reached. The attached log illustrates that CAS detects the TGT is expired and the TGT is removed however these same messages are written again every 2 minutes. We observe that the file still exists in the temp ehcache folder and does not get deleted until the “maxTimeToLiveInSeconds” is reached.

 

We are currently using 5.2.2-SNAPSHOT within a two server HA environment

 

cas.ticket.tgt.maxTimeToLiveInSeconds=28800

cas.ticket.tgt.timeToKillInSeconds=240

 

cas.ticket.registry.ehcache.replicateUpdatesViaCopy=true

cas.ticket.registry.ehcache.cacheManagerName=ticketRegistryCacheManager

cas.ticket.registry.ehcache.replicatePuts=true

cas.ticket.registry.ehcache.replicateUpdates=true

cas.ticket.registry.ehcache.memoryStoreEvictionPolicy=LRU

cas.ticket.registry.ehcache.configLocation=file:///opt/login-test/config/ehcache-replicated.xml

cas.ticket.registry.ehcache.maximumBatchSize=100

cas.ticket.registry.ehcache.shared=true

cas.ticket.registry.ehcache.replicationInterval=10000

cas.ticket.registry.ehcache.cacheTimeToLive=240

cas.ticket.registry.ehcache.diskExpiryThreadIntervalSeconds=0

cas.ticket.registry.ehcache.replicateRemovals=true

cas.ticket.registry.ehcache.maxChunkSize=5000000

cas.ticket.registry.ehcache.maxElementsOnDisk=0

cas.ticket.registry.ehcache.maxElementsInCache=0

cas.ticket.registry.ehcache.maxElementsInMemory=10000

cas.ticket.registry.ehcache.eternal=false

cas.ticket.registry.ehcache.loaderAsync=true

cas.ticket.registry.ehcache.replicatePutsViaCopy=true

cas.ticket.registry.ehcache.cacheTimeToIdle=240

cas.ticket.registry.ehcache.persistence=LOCALTEMPSWAP

cas.ticket.registry.ehcache.synchronousWrites=false

 

Any insight or thoughts would be great!

 

-Gary

 

.

EhcacheLogs.txt

Ray Bon

unread,
Feb 16, 2018, 6:40:41 PM2/16/18
to cas-...@apereo.org
Gary,

My understanding of ehcache is that it performs a wholesale cleanup. Based on your settings I would expect the checks would happen every 4 minutes.
Do you have multiple servers?
Each server will do its own routine checks on its own clock. The actions of some of those checks will be communication with peers. I could see ehcache holding a ticket until maxTimeToLiveInSeconds is reached, just because a ticket is expired does not mean that it should be purged from the cache.

Are you saying that after 240 seconds the TGT can still be used?
That would be a CAS bug. If you just expect the tickets to be gone, that is an ehcache issue.

Do you use 'remember me' option or is the longest a TGT can be used 240 seconds? 
If the latter, then set maxTimeToLiveInSeconds to the same value as timeToKillInSeconds.

Ray
-- 
Ray Bon
Programmer analyst
Development Services, University Systems
2507218831 | CLE 019 | rb...@uvic.ca

Maxwell, Gary

unread,
Feb 19, 2018, 1:37:21 PM2/19/18
to cas-...@apereo.org

Hi Ray,

 

Thank you for looking at this problem.

 

After the TGT times out, CAS continually tries to perform a purge of the TGT and writes out the following message over and over until it reaches the maximum lifetime. This is a problem just due to the volume of messages that are being generated for each user.

 

[INFO] 2018-02-19 08:38:52,239 org.apereo.cas.logout.DefaultLogoutManager performLogout - Performing logout operations for [TGT-**************************2JSFkHAz39-Poi85P7wTMGVm61SI0R0iSZMDzDU-2hxwuK4-login-test.fortlewis.edu]

[INFO] 2018-02-19 08:40:52,276 org.apereo.cas.logout.DefaultLogoutManager performLogout - Performing logout operations for [TGT-**************************2JSFkHAz39-Poi85P7wTMGVm61SI0R0iSZMDzDU-2hxwuK4-login-test.fortlewis.edu]

[INFO] 2018-02-19 08:42:52,306 org.apereo.cas.logout.DefaultLogoutManager performLogout - Performing logout operations for [TGT-**************************2JSFkHAz39-Poi85P7wTMGVm61SI0R0iSZMDzDU-2hxwuK4-login-test.fortlewis.edu]

[INFO] 2018-02-19 08:44:52,329 org.apereo.cas.logout.DefaultLogoutManager performLogout - Performing logout operations for [TGT-**************************2JSFkHAz39-Poi85P7wTMGVm61SI0R0iSZMDzDU-2hxwuK4-login-test.fortlewis.edu]

 

In our current production environment a CAS ticket is initially good for 4 hours but if the user continues to interact with CAS enabled applications that CAS ticket’s lifetime is extendable up to 8 hours.  We are currently running 4.0.3 in production and I have included a snippet from ticketExpirationPolicies.xml.  Does the same process I’ve described work in CAS 5.2.2?

 

<!-- TicketGrantingTicketExpirationPolicy: Default as of 3.5 -->

    <!-- Provides both idle and hard timeouts, for instance 2 hour sliding window with an 8 hour max lifetime -->

    <bean id="grantingTicketExpirationPolicy" class="org.jasig.cas.ticket.support.TicketGrantingTicketExpirationPolicy"

          p:maxTimeToLiveInSeconds="${tgt.maxTimeToLiveInSeconds:28800}"

           p:timeToKillInSeconds="${tgt.timeToKillInSeconds:14400}"/>

 

We do have “Remember Me” turned off.

 

-Gary

--
- Website:
https://apereo.github.io/cas
- Gitter Chatroom:
https://gitter.im/apereo/cas
- List Guidelines:
https://goo.gl/1VRrw7
- Contributions:
https://goo.gl/mh7qDG
---
You received this message because you are subscribed to the Google Groups "CAS Community" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
cas-user+u...@apereo.org.
To view this discussion on the web visit
https://groups.google.com/a/apereo.org/d/msgid/cas-user/1518824432.1763.55.camel%40uvic.ca.

Ray Bon

unread,
Feb 19, 2018, 2:23:18 PM2/19/18
to cas-...@apereo.org
Gary,

A sliding window is possible in CAS 5.2.2 (and earlier). I have not tried it since we use 'remember me' instead.

It is odd that CAS would be initiating the logout. The logout operations are part of a user requested logout, either accessing /cas/logout or logging out of an application that hits that page.
Is it possible that you have a rogue application that is attempting to initiate the logout?
Check your tomcat access logs (or whatever fronts CAS).

At INFO you should see the number of logouts for the TGT. Search your log for the first logout of that TGT.
        <!-- INFO  Performing logout operations for [TGT-...]
                   [number] logout requests were processed
             DEBUG ST, principal and URL -->
        <AsyncLogger name="org.apereo.cas.logout.DefaultLogoutManager" level="info">
            <Filters>
                <ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="NEUTRAL" />
                <RegexFilter regex="Captured logout request.*" onMismatch="DENY" />
            </Filters>
        </AsyncLogger>

At DEBUG, you will be able to track the logout(s) to a user and application.

If you only want to keep log volume down, add a filter:

<RegexFilter regex="Performing logout operations for.*" onMismatch="DENY" />

This would be heavy handed and not solve the problem.

Ray

Maxwell, Gary

unread,
Feb 23, 2018, 6:56:20 PM2/23/18
to cas-...@apereo.org

I did some more looking into how “EhCacheTicketRegistry.java” class is interfacing with Ehcache and not sure how this can be working for “cas.ticket.tgt.timeToKillInSeconds”.  

 

CAS gets an Element from Ehache within the getTicket() function. CAS then determines if it is expired. When CAS determines that it went past the idle time it performs a ehcache.remove(). The problem is that Ehcache always returns a false when it tries to remove it. The TGT is not being removed. I examined the properties of the Element to determine why Ehcache would not remove it and the Last Access date was updated to contain the time that the getTicket() function was executed. Ehcache must now think that it is active and not expired.  So basically I think when CAS is trying to remove a ticket that has timed out, Ehcache won’t do it because the last access date was updated during this process.

 

The cleaner however does remove the TGT when it hits  “maxTimeToLiveInSeconds”.

 

I tried to get around this problem by turning off the cleaner  and setting “DiskExpiryThreadIntervalSeconds” to 120 seconds.  That way Ehcache would remove it however the  Ehcache Expiry Thread however never runs.

Reply all
Reply to author
Forward
0 new messages