Infinite looping of SP in load balanced production instance

Tue Oct 29 15:16:51 EDT 2013

I have experienced this locally due to SSL problems or other errors,
so I know all the symptoms (and I've read through all the applicable
documentation), but this one really has me stumped. We have debug
level logging turned on for the IdP and the SP, and it has revealed no
obvious problems. As a matter of fact I can get all the way through
the process, and at the very last step when I'm redirected to the
original protected endpoint from the SP is when it responds with a
redirect to the IdP. The IdP seeing a valid session redirects back to
the SP, and it loops again. In my local instance this is the response
that gets returned for a success (I've changed nothing but the host):

https://sp-local.example.com/secure/Shibboleth.sso/SAML2/POST

Response

Cache-Control  private,no-store,no-cache,max-age=0
Connection  Keep-Alive
Content-Encoding  gzip
Content-Length  200
Content-Type  text/html; charset=iso-8859-1
Date  Tue, 29 Oct 2013 17:26:33 GMT
Expires  Wed, 01 Jan 1997 12:00:00 GMT
Keep-Alive  timeout=5, max=99
Location  https://sp-local.example.com/secure/
Server  Apache/2.2.22 (Win32) mod_ssl/2.2.22 OpenSSL/0.9.8t mod_jk/1.2.35
Set-Cookie  _shibsession_706f7274616c3368747470733a2f2f706f7274616c322e666f7265736565726573756c74732e636f6d2f636c69656e74=_dd253c7d3a8673dd5ee69e5594f5bff0;
path=/; secure
Vary  Accept-Encoding

This is the response that gets returned in production:

https://sp-prod.example.com/secure/Shibboleth.sso/SAML2/POST

Response

Cache-Control  private,no-store,no-cache,max-age=0
Connection  Keep-Alive
Content-Encoding  gzip
Content-Length  678
Content-Type  text/html; charset=iso-8859-1
Date  Tue, 29 Oct 2013 17:22:46 GMT
Expires  Wed, 01 Jan 1997 12:00:00 GMT
Keep-Alive  timeout=15, max=998
Location  https://sso-prod.example.com:443/idp/profile/SAML2/Redirect/SSO?SAMLRequest=jZLLTsMwEEV%2FJfK%2BcZKGPqymUmgXVCo0agoLNsh1J8SSYwePw%2BPvcZsiioQQm9nM9T0zdzxD3qiW5Z2r9RZeOkAXvDdKIzs1MtJZzQxHiUzzBpA5wcr8ds2SMGKtNc4Io0iQI4J10uiF0dg1YEuwr1LA%2FXadkdq5FhmlrbGOqySsjAUE8KVTDkNhGiqUBO1oWcv93ihwdYho6BGU0GJT7kiw9JNJzY%2BMb0cv%2BsWNpemQykNL%2FXyVVHD22cJBWhCeUm5IsFpm5Km6mh4EH4kUxISLURXBlKeTVPBoLNJ9VHkZYgcrjY5rl5EkioeDOBok0108ZknC0tEjCYpzDNdSH6R%2B%2FjuzfS9CdrPbFYN%2BtweweNrLC8h8dkyencD24hZ%2F2%2FKvA5D5v%2BOe0QtSj23ZnbdeLQujpPgIcqXM28ICd5CRmNB5%2F%2BTnf5l%2FAg%3D%3D&RelayState=ss%3Amem%3A902af1bd337b9a00c7cf2fd59df78ed09414e7114616afa29586daeaf280f267
Server  Apache
Set-Cookie  _shibpost_902af1bd337b9a00c7cf2fd59df78ed09414e7114616afa29586daeaf280f267=ss:mem:56d2bea39212e668ce31ca3e4d3fe10f52ad5f591a42fec1bc5cb4443be914ae;
path=/;secure
Vary  Accept-Encoding

We have a load balancer (SP only - we have a single IdP), and when I
change my host file so that the same SP is always hit we don't have
this problem. However, we've even configured the production host files
so that any outgoing requests for an SP are routed directly to the
same SP. Our load balancer is also sticky, and based upon what log
files get written everything seems to be sticky. It's only that last
POST that appears to be an issue. On the shibd.log side this is a
sample of where it begins the loop (I just don't know why):

2013-10-29 12:59:16 INFO Shibboleth.Listener : registered remoted
message endpoint (external::getHeaders::Application)
2013-10-29 12:59:16 INFO Shibboleth.Listener : listener service starting
2013-10-29 12:59:53 DEBUG Shibboleth.Listener [1]: dispatching message
(portal3::getHeaders::Application)
2013-10-29 12:59:53 DEBUG Shibboleth.Listener [1]: dispatching message
(default/Login::run::SAML2SI)
2013-10-29 12:59:53 DEBUG XMLTooling.StorageService [1]: inserted
record (a0dc6d20f91868a92329756828bcca9f19252d60db5bbe467ce22946ba6286b5)
in context (RelayState) with expiration (1383066593)
2013-10-29 12:59:53 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
validating input
2013-10-29 12:59:53 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
marshalling, deflating, base64-encoding the message
2013-10-29 12:59:53 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
marshalled message:
<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
AssertionConsumerServiceURL="https://sp-prod.example.com/secure/Shibboleth.sso/SAML2/POST"
Destination="https://sso-prod.example.com:443/idp/profile/SAML2/Redirect/SSO"
ID="_233e10a34fe69378551c36d3152c00a7"
IssueInstant="2013-10-29T16:59:53Z"
ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
Version="2.0"><saml:Issuer
xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">https://sp-prod.example.com/secure</saml:Issuer><samlp:NameIDPolicy
AllowCreate="1"/></samlp:AuthnRequest>
2013-10-29 12:59:53 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [1]:
message encoded, sending redirect to secure
2013-10-29 13:00:02 DEBUG Shibboleth.Listener [2]: dispatching message
(portal3::getHeaders::Application)
2013-10-29 13:00:02 DEBUG Shibboleth.Listener [2]: dispatching message
(default/Login::run::SAML2SI)
2013-10-29 13:00:02 DEBUG XMLTooling.StorageService [2]: inserted
record (a4d7264a73f04e1b45e36477743a3c19346626a0450a3b65fa0497a302bf3a4c)
in context (RelayState) with expiration (1383066602)
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
validating input
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
marshalling, deflating, base64-encoding the message
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
marshalled message:
<samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol"
AssertionConsumerServiceURL="https://sp-prod.example.com/secure/Shibboleth.sso/SAML2/POST"
Destination="https://sso-prod.example.com:443/idp/profile/SAML2/Redirect/SSO"
ID="_6375c581f9917004a8f6f2b65ecdf841"
IssueInstant="2013-10-29T17:00:02Z"
ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
Version="2.0"><saml:Issuer
xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion">https://sp-prod.example.com/secure</saml:Issuer><samlp:NameIDPolicy
AllowCreate="1"/></samlp:AuthnRequest>
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
message encoded, sending redirect to secure
2013-10-29 13:00:02 DEBUG Shibboleth.Listener [2]: dispatching message
(set::PostData)
2013-10-29 13:00:02 DEBUG XMLTooling.StorageService [2]: inserted
record (664b1fcaf9978fd43d6afa10582debb02695d876257d6d20ccbfcaef2ce14003)
in context (PostData) with expiration (1383066602)
2013-10-29 13:00:02 DEBUG Shibboleth.Listener [2]: dispatching message
(default/Login::run::SAML2SI)
2013-10-29 13:00:02 DEBUG XMLTooling.StorageService [2]: inserted
record (c666c2f6a911c8f7635c0bac6353e235d9ebc491bb2926a9ce149cb2d71c257a)
in context (RelayState) with expiration (1383066602)
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
validating input
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
marshalling, deflating, base64-encoding the message
2013-10-29 13:00:02 DEBUG OpenSAML.MessageEncoder.SAML2Redirect [2]:
marshalled message:

Any help would be greatly appreciated.