<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 TRANSITIONAL//EN">
<HTML>
<HEAD>
<META HTTP-EQUIV="Content-Type" CONTENT="text/html; CHARSET=UTF-8">
<META NAME="GENERATOR" CONTENT="GtkHTML/4.8.5">
</HEAD>
<BODY>
Hey all,<BR>
<BR>
I've been moving my QA environment over to shibboleth v3.2.1, and I have been trying to setup memcached for session management (especially SLO). Everything seems to be working correctly when all three memcached instances are running. However, I've run across an unexpected result (at least, unexpected for me...) when one of the memcached servers fails.<BR>
<BR>
I have setup my memcached storage service per the instructions here: <A HREF="https://wiki.shibboleth.net/confluence/display/IDP30/StorageConfiguration">https://wiki.shibboleth.net/confluence/display/IDP30/StorageConfiguration</A><BR>
<BR>
The test:<BR>
<BLOCKQUOTE>
User logs into a service provider. Result Success.<BR>
User logs out of service provider. Result Success.<BR>
<BR>
(clean browser):<BR>
User logs into a service provider. Result success.<BR>
* Stop one of the three memcached servers.<BR>
User logs out of a service provider. Result failure: SP reports ugly unknown principal error, idp logs the following:<BR>
<BR>
<BLOCKQUOTE>
<PRE>
2016-01-19 11:58:45,994 - ERROR [net.shibboleth.idp.session.impl.StorageBackedSessionManager:758] - Exception while querying based service ID <A HREF="https://myuvu-test.uvu.edu/shibboleth">https://myuvu-test.uvu.edu/shibboleth</A> and key AAdzZWNyZXQxlTZPIJ47nqajm+2idesfxm+5pGX9YHbT3PLhLrsQ+OypYa7x+oPoTw292ZqPhtJdnnz1ZEiqWDoIxayuzbOaKYuvgZa1uJ7uHt6fh4O0FKCRJm3CIV8TeyDVD9FPI9hWxAf1syiyeT1RM6w=
java.io.IOException: Memcached operation error
at org.opensaml.storage.impl.memcached.MemcachedStorageService.handleAsyncResult(MemcachedStorageService.java:611)
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Cancelled
at net.spy.memcached.internal.OperationFuture.get(OperationFuture.java:177)
Caused by: java.util.concurrent.CancellationException: Cancelled
at net.spy.memcached.internal.OperationFuture.get(OperationFuture.java:177)
2016-01-19 11:58:46,008 - ERROR [net.shibboleth.idp.saml.saml2.profile.impl.ProcessLogoutRequest:320] - Profile Action ProcessLogoutRequest: Error resolving matching session(s)
net.shibboleth.utilities.java.support.resolver.ResolverException: Exception while querying based on SPSession
at net.shibboleth.idp.session.impl.StorageBackedSessionManager.lookupBySPSession(StorageBackedSessionManager.java:760)
Caused by: java.io.IOException: Memcached operation error
at org.opensaml.storage.impl.memcached.MemcachedStorageService.handleAsyncResult(MemcachedStorageService.java:611)
Caused by: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Cancelled
at net.spy.memcached.internal.OperationFuture.get(OperationFuture.java:177)
Caused by: java.util.concurrent.CancellationException: Cancelled
at net.spy.memcached.internal.OperationFuture.get(OperationFuture.java:177)
2016-01-19 11:58:46,011 - WARN [org.opensaml.profile.action.impl.LogEvent:76] - An error event occurred while processing the request: SessionNotFound
</PRE>
</BLOCKQUOTE>
(clean browser): one memcached server still down:<BR>
User logs into a service provider. Result Success.<BR>
User logs out of service provider. Result Success.<BR>
<BR>
(clean browser): one memcached server still down:<BR>
User logs into a service provider. Result Success.<BR>
* Start back up the memcached server that was down.<BR>
* Wait until IdP connects back to the memcached server ( I enabled verbose logging on the memcached to see when this happened)<BR>
User logs out of a service provider. Result Failure<BR>
<BLOCKQUOTE>
SP reports the UnknownPrincipal FatalProfileException to the user.<BR>
IDP logs:
<BLOCKQUOTE>
<PRE>
2016-01-19 12:08:22,895 - INFO [net.shibboleth.idp.saml.saml2.profile.impl.ProcessLogoutRequest:315] - Profile Action ProcessLogoutRequest: No active session(s) found matching LogoutRequest
2016-01-19 12:08:22,898 - WARN [org.opensaml.profile.action.impl.LogEvent:76] - An error event occurred while processing the request: SessionNotFound
</PRE>
</BLOCKQUOTE>
<PRE>
memcached logs:
</PRE>
<BLOCKQUOTE>
<PRE>
<31 GET 000001525b3eb823:AAdzZWNyZXQxyQOTCwPrTRgaS8sEiE1QiBvwmEViuK/bKEIz3uJT427qhbjfvFv4e2B6LSdo2re4LFJ21o/bn/KvRPIxr1GwMnplqHqref445DBqWRTwyHkOKmnLHd+pMBk/MqC2OvrwThS/2VuozMJhkoI=
>31 Writing an error: Not found
</PRE>
</BLOCKQUOTE>
</BLOCKQUOTE>
(clean browser):<BR>
User logs into a service provider. Result Success.<BR>
User logs out of service provider. Result Success.<BR>
<BR>
</BLOCKQUOTE>
So, is this normal behavior, and I read too much into MemcachedStorageService's ability to handle failover? If I wanted to avoid users seeing the UnknownPrincipal errors during a situation like this, would switching to a database backed storage solve the issue? Are there any ways to better configure memcached to handle errors when a node is moving in and out of the memcached "cluster"?<BR>
<BR>
Thanks,<BR>
<BR>
-daniel
</BODY>
</HTML>