Re: [cas-user] ehcache replication issue between CAS 4.2.5 nodes.

[Ray Bon]

Boris,

One would think that 62 ms should be more than enough to transfer from one cache to another. We found that Ehcache was not fast enough in synchronous mode and had to move to a primary and failover setup.

Double check that the service ticket cache is using a synchronous replicator (mine is set in ticketRegistry.xml).

You can also look at the Ehcache log to see the puts (make sure the clocks on your servers are synced).
Turn net.sf.ehcache.distribution up first.
   
    <logger name="net.sf.ehcache" additivity="true">
        <level value="WARN" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="syslog" />
    </logger>
   
    <!-- at DEBUG prints Initialised cache: cache.name -->
    <logger name="net.sf.ehcache.Cache" additivity="false">
        <level value="ERROR" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="syslog" />
    </logger>
   
    <!-- at DEBUG prints disk store path -->
    <logger name="net.sf.ehcache.DiskStorePathManager" additivity="false">
        <level value="ERROR" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="syslog" />
    </logger>
   
    <!-- at DEBUG prints Found system property value of ... -->
    <logger name="net.sf.ehcache.config" additivity="false">
        <level value="ERROR" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="syslog" />
    </logger>
   
    <!-- at DEBUG prints remote ??? received and key -->
    <logger name="net.sf.ehcache.distribution" additivity="false">
        <level value="DEBUG" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="console" />
        <!-- <appender-ref ref="syslog" /> -->
    </logger>
   
    <logger name="net.sf.ehcache.store" additivity="false">
        <level value="WARN" />
        <appender-ref ref="ehcache" />
        <appender-ref ref="syslog" />
    </logger>

It is odd to you log in reverse chronological order. Did you do that manually or is it fed through a script?

Ray

On 2016-10-13 15:54, Boris Pogrebitskiy wrote:

Problem with Ehcache replication on Tomcat servers running 2 CAS 4.2.5 nodes. Looks like ST replication isn't working between 2 nodes.

Any help is appreciated. 

This is short version of log file showing that ST ticket was created on SecurityService02, but not found on SecurityService01 milliseconds later.

2016-10-13T22:22:06,503Z SecurityService02 null DEBUG org.jasig.cas.ticket.registry.EhCacheTicketRegistry [scheduler_Worker-5] [] : Ticket ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com is removed

2016-10-13T22:22:06,496Z SecurityService02 null DEBUG org.jasig.cas.ticket.registry.TicketRegistryCleaner [scheduler_Worker-5] [] : Cleaning up expired service ticket [ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com]

2016-10-13T22:21:21,482Z SecurityService01 null ERROR org.jasig.cas.web.ServiceValidateController [http-bio-18180-exec-13] [] : Failed to create proxy granting ticket for https://dv01.xxx.com/falcon/secure/receptororg.jasig.cas.ticket.InvalidTicketException: ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com

2016-10-13T22:21:21,481Z SecurityService01 null DEBUG org.jasig.cas.CentralAuthenticationServiceImpl [http-bio-18180-exec-13] [] : Ticket [ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com] by type [ServiceTicket] cannot be foundin the ticket registry.

2016-10-13T22:21:21,481Z SecurityService01 null DEBUG org.jasig.cas.ticket.registry.EhCacheTicketRegistry [http-bio-18180-exec-13] [] : No ticket by id [ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com] is found in the registry

2016-10-13T22:21:21,419Z SecurityService02 null DEBUG org.jasig.cas.CentralAuthenticationServiceImpl [http-bio-18280-exec-18] [] : Publishing org.jasig.cas.support.events.CasServiceTicketGrantedEvent@57d7da6a[ticketGrantingTicket=org.jasig.cas.ticket.registry.TicketGrantingTicketDelegator@9aaeddec,serviceTicket=ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com]

2016-10-13T22:21:21,419Z SecurityService02 null INFO  org.jasig.cas.CentralAuthenticationServiceImpl [http-bio-18280-exec-18] [] : Granted ticket [ST-10-IAhAyqLGE6eBJAnHCViP-dv01sec001.xxx.com] for service [https://dv01.xxx.com/falcon/j_spring_cas_security_check] and principal [ELUX/dummytest]

BUT i also see following messages in the log:

-------

2016-10-13T21:59:27,865Z SecurityService01 null DEBUG net.sf.ehcache.distribution.RMIBootstrapCacheLoader [Bootstrap Thread for cache iqn_ServiceTicket] [] : Empty list of cache peers for cache iqn_ServiceTicket. No cache peer to bootstrap from.

2016-10-13T21:59:27,865Z SecurityService01 null DEBUG net.sf.ehcache.distribution.RMIBootstrapCacheLoader [Bootstrap Thread for cache iqn_ServiceTicket] [] : cache peers: []

-------

2016-10-13T21:59:36,508Z SecurityService02 null DEBUG net.sf.ehcache.distribution.RMICacheManagerPeerProviderFactory [localhost-startStop-1] [] : Registering peer //dv01sec001.xxx.com:41001/cas_st

2016-10-13T21:59:36,508Z SecurityService02 null DEBUG net.sf.ehcache.distribution.RMICacheManagerPeerProviderFactory [localhost-startStop-1] [] : Registering peer //dv01sec001.xxx.com:41001/cas_tgt

2016-10-13T21:59:25,834Z SecurityService01 null DEBUG net.sf.ehcache.distribution.RMICacheManagerPeerProviderFactory [localhost-startStop-1] [] : Registering peer //dv01sec001.xxx.com:41002/cas_tgt

2016-10-13T21:59:25,834Z SecurityService01 null DEBUG net.sf.ehcache.distribution.RMICacheManagerPeerProviderFactory [localhost-startStop-1] [] : Registering peer //dv01sec001.xxx.com:41002/cas_st

CAS Ehcache configuration:

##

# Ehcache Ticket Registry settings required until we can completly remove Ehcache

# can skip some of these properties to use default defined in WEB-INF/spring-configuration/ehcache-ticket-registry.xml

#

ehcache.config.file=classpath:ehcache-replicated.xml

ehcache.cachemanager.shared=true

ehcache.cachemanager.name=iqn_ticketRegistryCacheManager

ehcache.disk.expiry.interval.seconds=0

ehcache.disk.persistent=false

ehcache.eternal=false

ehcache.max.elements.memory=10000

ehcache.max.elements.disk=20000

ehcache.eviction.policy=LRU

ehcache.overflow.disk=true

ehcache.cache.st.name=iqn_ServiceTicket

ehcache.cache.st.timeIdle=0

ehcache.cache.st.timeAlive=300

ehcache.cache.tgt.name=iqn_TicketGrantingTicket

ehcache.cache.tgt.timeIdle=0

ehcache.cache.tgt.timeAlive=7201

ehcache.cache.loader.async=true

ehcache.cache.loader.chunksize=5000000

ehcache.repl.async.interval=10000

ehcache.repl.async.batch.size=100

ehcache.repl.sync.puts=true

ehcache.repl.sync.putscopy=true

ehcache.repl.sync.updates=true

ehcache.repl.sync.updatesCopy=true

ehcache.repl.sync.removals=true

--
CAS gitter chatroom: https://gitter.im/apereo/cas
CAS mailing list guidelines: https://apereo.github.io/cas/Mailing-Lists.html
CAS documentation website: https://apereo.github.io/cas
CAS project website: https://github.com/apereo/cas
---
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 post to this group, send email to cas-...@apereo.org.
Visit this group at https://groups.google.com/a/apereo.org/group/cas-user/.
To view this discussion on the web visit https://groups.google.com/a/apereo.org/d/msgid/cas-user/856d0605-b249-471f-bc5d-644598799e1a%40apereo.org.
For more options, visit https://groups.google.com/a/apereo.org/d/optout.

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

[Boris Pogrebitskiy]

RESOLVED. 

Found that old ehcache-replicated.xml file on servers had cache names that didn't match cas.properties 

Thank you,

Boris Pogrebitskiy | IQNavigator | Sr. Java Developer

(303) 731-6643 • bpogre...@iqn.com
6465 Greenwood Plaza Blvd. • Suite 800 • Centennial, CO • 80111 • USA  

 “If you have knowledge , let others light their candles in it.” - Margaret Fuller

To unsubscribe from this group and stop receiving emails from it, send an email to cas-user+unsubscribe@apereo.org.