We’re having the same issue here. Does anyone have CAS working behind the F5 or is it just broken?
Thanks, Niva From: [email protected] [mailto:[email protected]] On Behalf Of Yan Zhou Sent: Wednesday, August 3, 2016 11:13 AM To: CAS Community <[email protected]> Subject: [cas-user] memcached registry, failed fetching error Hi there, We have two CAS server behind F5 load balancer, each runs memcached. cas.properties on both server reads: memcached.servers=dcasde01.dev.medplus.com:11211, dcasde02.dev.medplus.com:11211 the problem I run into intermittently, is that server 1 issues a service ticket and /serviceValidate is called immediately on server 2, but server 2 cannot find the service ticket. I turned on debug mode on net.spy.memcached client, still cannot figure out what was wrong. Thanks, Yan dcasde01 (server 1) node: it generates ST, write and read complete ==================================================== 2016-08-02 19:18:19,261 DEBUG [net.spy.memcached.MemcachedConnection] - Added Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777 to {QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=0, #iq=1, topRop=null, topWop=null, toWrite=0, interested=0} 2016-08-02 19:18:19,263 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@6418da19<mailto:sun.nio.ch.SelectionKeyImpl@6418da19> (r=false, w=true, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777, toWrite=0, interested=4}) 2016-08-02 19:18:19,263 DEBUG [net.spy.memcached.protocol.binary.StoreOperationImpl] - Transitioned state from WRITE_QUEUED to WRITING 2016-08-02 19:18:19,264 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - After copying stuff from Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777: java.nio.DirectByteBuffer[pos=859 lim=16384 cap=16384] 2016-08-02 19:18:19,264 DEBUG [net.spy.memcached.protocol.binary.StoreOperationImpl] - Transitioned state from WRITING to READING 2016-08-02 19:18:19,264 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - Finished writing Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777 2016-08-02 19:18:19,265 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@6418da19<mailto:sun.nio.ch.SelectionKeyImpl@6418da19> (r=true, w=false, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=1, #Wops=0, #iq=0, topRop=Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777, topWop=null, toWrite=0, interested=1}) 2016-08-02 19:18:19,266 DEBUG [net.spy.memcached.MemcachedConnection] - Completed read op: Cmd: 2 Opaque: 17 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com Cas: 0 Exp: 10 Flags: 0 Data Length: 777 and giving the next 0 bytes 2016-08-02 19:18:19,267 DEBUG [net.spy.memcached.MemcachedConnection] - Selecting with delay of 1000ms 2016-08-02 19:18:19,267 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] - Granted ticket [ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com] for service [https://intcas.dev.medplus.com/cas-services/login/cas] for user [castempadmin] 2016-08-02 19:18:19,267 DEBUG [net.spy.memcached.MemcachedConnection] - Added Cmd: 0 Opaque: 18 Key: TGT-TGT-**********************************************DfT6jtz6yn-dcasde01.dev.medplus.com to {QA sa=dcasde02.dev.medplus.com/172.18.38.131:11211, #Rops=0, #Wops=0, #iq=1, topRop=null, topWop=null, toWrite=0, interested=0} 2016-08-02 19:18:19,294 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN ============================================================= WHO: castempadmin WHAT: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com for https://intcas.dev.medplus.com/cas-services/login/cas ACTION: SERVICE_TICKET_CREATED APPLICATION: CAS WHEN: Tue Aug 02 19:18:19 UTC 2016 CLIENT IP ADDRESS: 172.18.100.57 SERVER IP ADDRESS: 172.18.38.130 ============================================================= dcasde02 (server 2) node access logs, /serviceValidate is called immediately afterwards ============================================================================= 172.18.38.131 - - [02/Aug/2016:19:18:20 +0000] "GET /cas/p3/serviceValidate?ticket=ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com&service=https%3A%2F%2Fintcas.dev.medplus.com%2Fcas-services%2Flogin%2Fcas HTTP/1.1" 200 271 "-" "Java/1.7.0_75" 172.18.100.57 - - [02/Aug/2016:19:18:21 +0000] "GET /cas-services/login/cas?ticket=ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com HTTP/1.1" 302 - "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:47.0) Gecko/20100101 Firefox/47.0" dcasde02 (server 2) node, it failed fetching and again writes to memcached running on the other server ============================================================================= 2016-08-02 19:18:19,597 DEBUG [net.spy.memcached.MemcachedConnection] - Added Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com to {QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=0, #iq=1, topRop=null, topWop=null, toWrite=0, interested=0} 2016-08-02 19:18:19,599 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@774ead62<mailto:sun.nio.ch.SelectionKeyImpl@774ead62> (r=false, w=true, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, toWrite=0, interested=4}) 2016-08-02 19:18:19,604 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - After copying stuff from Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com: java.nio.DirectByteBuffer[pos=74 lim=16384 cap=16384] 2016-08-02 19:18:19,604 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - Finished writing Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com 2016-08-02 19:18:19,606 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@774ead62<mailto:sun.nio.ch.SelectionKeyImpl@774ead62> (r=true, w=false, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=1, #Wops=0, #iq=0, topRop=Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, topWop=null, toWrite=0, interested=1}) 2016-08-02 19:18:19,609 DEBUG [net.spy.memcached.MemcachedConnection] - Completed read op: Cmd: 0 Opaque: 1 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com and giving the next 0 bytes 2016-08-02 19:18:19,618 ERROR [org.jasig.cas.ticket.registry.MemCacheTicketRegistry] - Failed fetching [ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, java.lang.RuntimeException: Exception waiting for value] 2016-08-02 19:18:19,618 INFO [org.jasig.cas.CentralAuthenticationServiceImpl] - Service ticket [ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com] does not exist. 2016-08-02 19:18:19,621 DEBUG [net.spy.memcached.MemcachedConnection] - Added Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com to {QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=0, #iq=1, topRop=null, topWop=null, toWrite=0, interested=0} 2016-08-02 19:18:19,622 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@774ead62<mailto:sun.nio.ch.SelectionKeyImpl@774ead62> (r=false, w=true, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, toWrite=0, interested=4}) 2016-08-02 19:18:19,623 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - After copying stuff from Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com: java.nio.DirectByteBuffer[pos=74 lim=16384 cap=16384] 2016-08-02 19:18:19,623 DEBUG [net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl] - Finished writing Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com 2016-08-02 19:18:19,624 DEBUG [net.spy.memcached.MemcachedConnection] - Handling IO for: sun.nio.ch.SelectionKeyImpl@774ead62<mailto:sun.nio.ch.SelectionKeyImpl@774ead62> (r=true, w=false, c=false, op={QA sa=dcasde01.dev.medplus.com/172.18.38.130:11211, #Rops=1, #Wops=0, #iq=0, topRop=Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, topWop=null, toWrite=0, interested=1}) 2016-08-02 19:18:19,625 DEBUG [net.spy.memcached.MemcachedConnection] - Completed read op: Cmd: 0 Opaque: 2 Key: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com and giving the next 0 bytes 2016-08-02 19:18:19,627 ERROR [org.jasig.cas.ticket.registry.MemCacheTicketRegistry] - Failed fetching [ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com, java.lang.RuntimeException: Exception waiting for value] 2016-08-02 19:18:19,635 INFO [org.jasig.inspektr.audit.support.Slf4jLoggingAuditTrailManager] - Audit trail record BEGIN ============================================================= WHO: audit:unknown WHAT: ST-2-IuotzVXFdjPUucLs2ZVm-dcasde01.dev.medplus.com ACTION: SERVICE_TICKET_VALIDATE_FAILED APPLICATION: CAS WHEN: Tue Aug 02 19:18:19 UTC 2016 CLIENT IP ADDRESS: 172.18.38.131 SERVER IP ADDRESS: 172.18.38.131 ============================================================= -- 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 [email protected]<mailto:[email protected]>. To post to this group, send email to [email protected]<mailto:[email protected]>. 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/da054b55-0ac1-4c81-9889-b304b2d45747%40apereo.org<https://groups.google.com/a/apereo.org/d/msgid/cas-user/da054b55-0ac1-4c81-9889-b304b2d45747%40apereo.org?utm_medium=email&utm_source=footer>. For more options, visit https://groups.google.com/a/apereo.org/d/optout. -- 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 [email protected]. To post to this group, send email to [email protected]. 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/1b1c706a981c4835a32280367ba86615%40exch15-mr03.tu.temple.edu. For more options, visit https://groups.google.com/a/apereo.org/d/optout.
