Reputation: 607
Infinite loop for SAML request in spring-saml

I am seeing extremely wired and inconsistent behavior in webapp with spring-saml.
Our setup -
Two IDP being chosen based on url pattern - implemented using CustomSAMLContextProviderImpl (works fine based on url it redirects to configured IDP)
Configured both SAML provider/IDP using CachingMetadataManager with list of ExtendedMetadataDelegate. Based on explaination here and code-example
spring mvc application (version - 4.1.6.RELEASE)
spring saml security (version - 1.0.1.RELEASE)
Now, sometime I observe infinite looping behavior between IDP(https://default-idp.com/sso/idp/SAML2) and SP (https://my-application.com/).
Attaching piece of log
    16:29:07.829 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default SP/Local EntityId https://my-application.com/
16:29:07.829 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:29:07.829 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:29:07.829 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain a descriptor for entity https://my-application.com/
16:29:07.829 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain any role descriptors of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity https://my-application.com/
16:29:07.830 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document does not contain a role of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol urn:oasis:names:tc:SAML:2.0:protocol for entity https://my-application.com/
16:29:07.830 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:29:07.830 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:29:07.831 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:29:07.831 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:29:07.831 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:29:07.832 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:29:07.832 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:29:07.832 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:29:07.845 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://javax.xml.XMLConstants/feature/secure-processing'
16:29:07.846 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/dom/defer-node-expansion'
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/disallow-doctype-decl'
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default IDP/Peer EntityId https://default-idp.com/sso/idp/SAML2
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://default-idp.com/sso/idp/SAML2
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://default-idp.com/sso/idp/SAML2
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.util.SAMLUtil - Index for AssertionConsumerService not specified, returning default
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.SAMLEntryPoint - Processing SSO using WebSSO profile
16:29:07.847 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.s.s.saml.websso.WebSSOProfileImpl - Using default consumer service with binding urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Beginning encode message to outbound transport of type: org.opensaml.ws.transport.http.HttpServletResponseAdapter
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Deflating and Base64 encoding SAML message
16:29:07.848 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Marshalling message
16:29:07.850 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Building URL to redirect client to
16:29:07.850 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generating signature with key type 'RSA', algorithm URI 'http://www.w3.org/2000/09/xmldsig#rsa-sha1' over query string 'SAMLRequest=jVJLa8JAEL73V4S956n4WEzEVqSCxWBiD72tu6MuJLtxZxPaf9%2FEKLWX0tMwMN%2BD75vZ%2FLMsnAYMSq1iEnoBcUBxLaQ6xWSfr9wJmSdPM2RlEVV0Uduz2sGlBrTOAhGMbXEvWmFdgsnANJLDfreJydnaCqnvX5iHX%2BWJ1SfwGJ6jbuMVeFyXfkfqZ9mWOMuWTypmrybuUAGNK5V1S2G8CyvYATswUxZ4D0ftS1H52eJtExFnpQ2Hq8GYHFmBQJz1MiYsHB%2BOo0MwCIdSiDAYiLNgRyZ4xKftbI8wZYiygR8YYg1rhbbVikkUhCM3GLjhNA9HNJrSYOxNhpMP4qRGW8118SxVn1dtFNUMJVLFSkBqOe3M0cgL6KE%2FQvqa56mbbrOcOO%2F33KMu97YJhbRP%2Bm%2Bu6iZMkr4YenVsHhn%2BJmD36kjyj6Jm%2FqNKclt%2Ff0PyDQ%3D%3D&SigAlg=http%3A%2F%2Fwww.w3.org%2F2000%2F09%2Fxmldsig%23rsa-sha1'
16:29:07.851 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computing signature over input using private key of type RSA and JCA algorithm ID SHA1withRSA
16:29:07.860 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computed signature: 0ab25de333a8968a0fca40329d52d1e0fef52ecc3aeb94bf5a8e956b560f63ca47bdea64f1611281f29320c5997734dc61dd7adf2b87a44d16f3f639d05221b06909679168996536629bfa72606bd06f95c8bd83ce8ddea4bda13159e40cfbe51f9dcd37f556cf2b465367a180567f5e9d95092b41f42447ec57d77c4c66d7d0615cacf28003422e752da78ea12b274d2bd79df35686a34ed29e3a09c967f29c1b3acbe0c752384b17d7e60f5281e07d6961dedbd2778ea872c6c0be211c154bcdb663c0d14c8accdb61084e8d52acdf76e3496249a952571632a722146cd9515058fe81fbc81abc1de75ee5fe228519f5e5dd2441497c019580795ec1c81520
16:29:07.860 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generated digital signature value (base64-encoded) CrJd4zOolooPykAynVLR4P71Lsw665S/Wo6Va1YPY8pHvepk8WESgfKTIMWZdzTcYd163yuHpE0W8/Y50FIhsGkJZ5FomWU2Ypv6cmBr0G+VyL2Dzo3epL2hMVnkDPvlH53NN/VWzytGU2ehgFZ/Xp2VCStB9CRH7FfXfExm19BhXKzygANCLnUtp46hKydNK9ed81aGo07SnjoJyWfynBs6y+DHUjhLF9fmD1KB4H1pYd7b0neOqHLGwL4hHBVLzbZjwNFMiszbYQhOjVKs33bjSWJJqVJXFjKnIhRs2VFQWP6B+8gavB3nXuX+IoUZ9eXdJEFJfAGVgHlewcgVIA==
16:29:07.860 [ajp-bio-8009-exec-1] DEBUG PROTOCOL_MESSAGE - 
<?xml version="1.0" encoding="UTF-8"?>
<saml2p:AuthnRequest
    AssertionConsumerServiceURL="https://my-application.com//saml/SSO"
    Destination="https://default-idp.com/sso/idp/SAML2"
    ForceAuthn="false" ID="a17bf6b0314idd103dhdafadc2c9afa"
    IsPassive="false" IssueInstant="2016-03-19T16:29:07.848Z"
    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
    Version="2.0" xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol">
    <saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">https://my-application.com/</saml2:Issuer>
</saml2p:AuthnRequest>

16:29:07.860 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Successfully encoded message.
16:29:07.860 [ajp-bio-8009-exec-1] DEBUG o.s.s.s.storage.HttpSessionStorage - Storing message a17bf6b0314idd103dhdafadc2c9afa to session 09CFF767DEC97C3B752DBD9E609B15DF
16:29:07.860 [ajp-bio-8009-exec-1] INFO  o.s.s.saml.log.SAMLDefaultLogger - AuthNRequest;SUCCESS;127.0.0.1;https://my-application.com/;https://default-idp.com/sso/idp/SAML2;;;
#BOOKMARK-REQUEST-ENDS
# EXPECTS = DEBUG o.s.s.saml.SAMLProcessingFilter - Attempting SAML2 authentication using profile urn:oasis:names:tc:SAML:2.0:profiles:SSO:browser
#BOOKMARK-REQUEST-STARTS
16:30:50.203 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default SP/Local EntityId https://my-application.com/
16:30:50.203 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:30:50.203 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:30:50.203 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain a descriptor for entity https://my-application.com/
16:30:50.203 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain any role descriptors of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity https://my-application.com/
16:30:50.204 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document does not contain a role of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol urn:oasis:names:tc:SAML:2.0:protocol for entity https://my-application.com/
16:30:50.204 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:30:50.204 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:30:50.205 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:30:50.219 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://javax.xml.XMLConstants/feature/secure-processing'
16:30:50.219 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/dom/defer-node-expansion'
16:30:50.220 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/disallow-doctype-decl'
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default IDP/Peer EntityId https://default-idp.com/sso/idp/SAML2
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://default-idp.com/sso/idp/SAML2
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://default-idp.com/sso/idp/SAML2
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.util.SAMLUtil - Index for AssertionConsumerService not specified, returning default
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.SAMLEntryPoint - Processing SSO using WebSSO profile
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:30:50.221 [ajp-bio-8009-exec-1] DEBUG o.s.s.saml.websso.WebSSOProfileImpl - Using default consumer service with binding urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
16:30:50.222 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Beginning encode message to outbound transport of type: org.opensaml.ws.transport.http.HttpServletResponseAdapter
16:30:50.222 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Deflating and Base64 encoding SAML message
16:30:50.222 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Marshalling message
16:30:50.224 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Building URL to redirect client to
16:30:50.224 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generating signature with key type 'RSA', algorithm URI 'http://www.w3.org/2000/09/xmldsig#rsa-sha1' over query string 'SAMLRequest=jVLJbsIwEL33KyLfs5myWSSIFqEiURWR0ENvxkwTS4kdPE7U%2Fn0TAiq9oB5Hepvem9n8qyycBgxKrSISegFxQAl9lCqLyD5duRMyjx9myMuCVmxR21zt4FQDWmeBCMa2vGetsC7BJGAaKWC%2F20Qkt7ZC5vsn7uF3mfE6A49jTrtLVOAJXfqdqJ8kb8RZtnpScXsOcaUeoXGlsm55NN6JF%2FyAHZkrC6Kno%2FblsfKTxeuGEmeljYBzwIh88gKBOOtlRLgYZmOZc3kYwUAOaC7HUownU55lj8MOg1uOKBv4ZSHWsFZoW6uI0CAcucHADadpOGKDgA0Dj9Lwgzhbo60WuniSqq%2BrNoppjhKZ4iUgs4J12Rj1AnboQche0nTrbt%2BSlDjv19ppV3s7hELWF31fq7oYk7jfhZ0Tm1uF%2BwL8uhyJ%2F7HTzL91iS%2Fn32eIfwA%3D&SigAlg=http%3A%2F%2Fwww.w3.org%2F2000%2F09%2Fxmldsig%23rsa-sha1'
16:30:50.224 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computing signature over input using private key of type RSA and JCA algorithm ID SHA1withRSA
16:30:50.232 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computed signature: 7901bedd79bd271365601068be83596e5932a902cc36af693f47ce9f63a2ac9387403c713951673ec712f8cc22efe2a13772616f3a82d1c14eee7547fd04f9366e963c62d8af31fd53eb4ded9b3a1869a8df0c0a52b901621a5ec7c9ff5d92b3e7a918de5b7fad61002ffcf8fa3766c8fa2aeba9d5102db80073805d947f8d1334197b228d629769d79968ab448d36090e4362e2bc9b6149161e3aebfe9b2ebf07b76654e58ca2f05ed02a0e3939c266c04b259a9d1b4cc1fc4f124a8c43d029c8e5e1de6f5ed898762f4231dc182fd1855e5316fcd1d13438de85d31f3700757006c3c6f3436a644bad1ac149effdc75effcfecd138219b0f72ef3ada54b306
16:30:50.232 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generated digital signature value (base64-encoded) eQG+3Xm9JxNlYBBovoNZblkyqQLMNq9pP0fOn2OirJOHQDxxOVFnPscS+Mwi7+KhN3JhbzqC0cFO7nVH/QT5Nm6WPGLYrzH9U+tN7Zs6GGmo3wwKUrkBYhpex8n/XZKz56kY3lt/rWEAL/z4+jdmyPoq66nVEC24AHOAXZR/jRM0GXsijWKXadeZaKtEjTYJDkNi4rybYUkWHjrr/psuvwe3ZlTljKLwXtAqDjk5wmbASyWanRtMwfxPEkqMQ9ApyOXh3m9e2Jh2L0Ix3Bgv0YVeUxb80dE0ON6F0x83AHVwBsPG80NqZEutGsFJ7/3HXv/P7NE4IZsPcu862lSzBg==
16:30:50.233 [ajp-bio-8009-exec-1] DEBUG PROTOCOL_MESSAGE - 
<?xml version="1.0" encoding="UTF-8"?>
<saml2p:AuthnRequest
    AssertionConsumerServiceURL="https://my-application.com//saml/SSO"
    Destination="https://default-idp.com/sso/idp/SAML2"
    ForceAuthn="false" ID="ac5g7ihaib6e3i32hi7ic789agg45e"
    IsPassive="false" IssueInstant="2016-03-19T16:30:50.221Z"
    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
    Version="2.0" xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol">
    <saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">https://my-application.com/</saml2:Issuer>
</saml2p:AuthnRequest>

16:30:50.233 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Successfully encoded message.
16:30:50.233 [ajp-bio-8009-exec-1] DEBUG o.s.s.s.storage.HttpSessionStorage - Storing message ac5g7ihaib6e3i32hi7ic789agg45e to session 5E6F51ACA1C337DFEA1BAE43F8C0B17D
16:30:50.233 [ajp-bio-8009-exec-1] INFO  o.s.s.saml.log.SAMLDefaultLogger - AuthNRequest;SUCCESS;127.0.0.1;https://my-application.com/;https://default-idp.com/sso/idp/SAML2;;;
#BOOKMARK-REQUEST-ENDS
# EXPECTS = DEBUG o.s.s.saml.SAMLProcessingFilter - Attempting SAML2 authentication using profile urn:oasis:names:tc:SAML:2.0:profiles:SSO:browser
#REFRESH-METADATA-STARTS
16:31:06.138 [Timer-0] DEBUG o.o.s.m.p.AbstractReloadingMetadataProvider - Beginning refresh of metadata from '/opt/CONFIG/APP/metadata/idp-meta-nsl.xml'
16:31:06.139 [Timer-0] DEBUG o.o.s.m.p.ResourceBackedMetadataProvider - resource /opt/CONFIG/APP/metadata/idp-meta-nsl.xml was last modified 2016-02-05T00:02:42.000Z
16:31:06.139 [Timer-0] DEBUG o.o.s.m.p.AbstractReloadingMetadataProvider - Metadata from '/opt/CONFIG/APP/metadata/idp-meta-nsl.xml' has not changed since last refresh
16:31:06.139 [Timer-0] DEBUG o.o.s.m.p.AbstractReloadingMetadataProvider - Computing new expiration time for cached metadata from '/opt/CONFIG/APP/metadata/idp-meta-nsl.xml
16:31:06.140 [Timer-0] INFO  o.o.s.m.p.AbstractReloadingMetadataProvider - Next refresh cycle for metadata provider '/opt/CONFIG/APP/metadata/idp-meta-nsl.xml' will occur on '2016-03-19T16:36:06.140Z' ('2016-03-19T16:36:06.140Z' local time)
16:36:06.141 [Timer-0] DEBUG o.o.s.m.p.AbstractReloadingMetadataProvider - Beginning refresh of metadata from '/opt/CONFIG/APP/metadata/idp-meta-nsl.xml'
#BOOKMARK-REFRESH-METADATA-STARTS
#BOOKMARK-REQUEST-STARTS
16:59:09.514 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default SP/Local EntityId https://my-application.com/
16:59:09.515 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain a descriptor for entity https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document did not contain any role descriptors of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor for entity https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Metadata document does not contain a role of type {urn:oasis:names:tc:SAML:2.0:metadata}SPSSODescriptor supporting protocol urn:oasis:names:tc:SAML:2.0:protocol for entity https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://my-application.com/
16:59:09.516 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://my-application.com/
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Building credential from keystore entry for entityID sam, usage type UNSPECIFIED
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.KeyStoreCredentialResolver - Processing PrivateKeyEntry from keystore
16:59:09.517 [ajp-bio-8009-exec-1] DEBUG o.o.x.s.c.c.EvaluableCredentialCriteriaRegistry - Registry located evaluable criteria class org.opensaml.xml.security.credential.criteria.EvaluableEntityIDCredentialCriteria for criteria class org.opensaml.xml.security.criteria.EntityIDCriteria
16:59:09.531 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://javax.xml.XMLConstants/feature/secure-processing'
16:59:09.532 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/dom/defer-node-expansion'
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.xml.parse.StaticBasicParserPool - Setting DocumentBuilderFactory attribute 'http://apache.org/xml/features/disallow-doctype-decl'
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG c.s.s.s.CustomSAMLContextProviderImpl - Using default IDP/Peer EntityId https://default-idp.com/sso/idp/SAML2
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.ChainingMetadataProvider - Checking child metadata provider for entity descriptor with entity ID: https://default-idp.com/sso/idp/SAML2
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.p.AbstractMetadataProvider - Searching for entity descriptor with an entity ID of https://default-idp.com/sso/idp/SAML2
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.util.SAMLUtil - Index for AssertionConsumerService not specified, returning default
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.s.security.saml.SAMLEntryPoint - Processing SSO using WebSSO profile
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selecting default IndexedEndpoint
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.o.s.m.support.SAML2MetadataHelper - Selected IndexedEndpoint with explicit isDefault of true
16:59:09.533 [ajp-bio-8009-exec-1] DEBUG o.s.s.saml.websso.WebSSOProfileImpl - Using default consumer service with binding urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST
16:59:09.534 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Beginning encode message to outbound transport of type: org.opensaml.ws.transport.http.HttpServletResponseAdapter
16:59:09.534 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Deflating and Base64 encoding SAML message
16:59:09.534 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Marshalling message
16:59:09.536 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Building URL to redirect client to
16:59:09.536 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generating signature with key type 'RSA', algorithm URI 'http://www.w3.org/2000/09/xmldsig#rsa-sha1' over query string 'SAMLRequest=jVLLasJAFN33K8Ls89SIGUzEVqSCRTFpF92Nk6sZSWbi3Im0f9%2FEKLUb6fLCeXHOnUy%2FqtI6g0ahZEx8xyMWSK5yIQ8xec8W9phMk6cJsqoMajprTCG3cGoAjTVDBG1a3ouS2FSgU9BnweF9u4pJYUyN1HVPzMHv6sCaAzgMi6C7eA0OV5XbibppuibWvNUTkplLiBs1h7MtpLGrXDsnVrIddmQmDfCejsoVee2ms7dVQKyF0hwuAWOyZyUCsZbzmLBgGIp9uIOhPx4ci9CPjsWQ7cZcHAd51GJwwxDFGX5ZiA0sJZrWKiaB549sb2D7UeaPaBhRL3LCwfCTWButjOKqfBayr6vRkiqGAqlkFSA1nHbZaOB4dNeDkL5m2cberNOMWB%2B32oOu9nYIibQv%2BrFWfTUmSb8LvSTW9wqPBdhtOZL8Y6eJe%2B%2BSXM%2B%2Fz5D8AA%3D%3D&SigAlg=http%3A%2F%2Fwww.w3.org%2F2000%2F09%2Fxmldsig%23rsa-sha1'
16:59:09.536 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computing signature over input using private key of type RSA and JCA algorithm ID SHA1withRSA
16:59:09.544 [ajp-bio-8009-exec-1] DEBUG o.opensaml.xml.security.SigningUtil - Computed signature: 3f398705a802aab6e084e3fa021f94e773e66d864f5fa71208bd96ca3312525f8bbf7fb914e6b2ab606cada63b4a3846280fe833d250c7c44050267c94bde585c283f5bf6876e6cfed238191fe2a0b03c7a6fb34651144a132bb7bd8485b0eec466f84b748fb6f10a11329e667279ebd141c8e48dfa1284863ad92ed6c0fbf7ec925a61fe2d305a028913c876b4e9d9558372bac13789362cc2010557c2d863da13ccbcc17cc322dab85308dd495b31fd008ada4813361da5cb7d5ee111d0f457e8a3b0c37bf2653cdbb99812bef0736c686b454babf699c8839d55d6a846fd1f9efc0f7a5649526a6a4230f53362a0ab9a3ca284393b4b2b81c0e7d6688db4d
16:59:09.544 [ajp-bio-8009-exec-1] DEBUG o.o.s.b.e.HTTPRedirectDeflateEncoder - Generated digital signature value (base64-encoded) PzmHBagCqrbghOP6Ah+U53PmbYZPX6cSCL2WyjMSUl+Lv3+5FOayq2BsraY7SjhGKA/oM9JQx8RAUCZ8lL3lhcKD9b9odubP7SOBkf4qCwPHpvs0ZRFEoTK7e9hIWw7sRm+Et0j7bxChEynmZyeevRQcjkjfoShIY62S7WwPv37JJaYf4tMFoCiRPIdrTp2VWDcrrBN4k2LMIBBVfC2GPaE8y8wXzDItq4UwjdSVsx/QCK2kgTNh2ly31e4RHQ9Ffoo7DDe/JlPNu5mBK+8HNsaGtFS6v2mciDnVXWqEb9H578D3pWSVJqakIw9TNioKuaPKKEOTtLK4HA59ZojbTQ==
16:59:09.545 [ajp-bio-8009-exec-1] DEBUG PROTOCOL_MESSAGE - 
<?xml version="1.0" encoding="UTF-8"?>
<saml2p:AuthnRequest
    AssertionConsumerServiceURL="https://my-application.com//saml/SSO"
    Destination="https://default-idp.com/sso/idp/SAML2"
    ForceAuthn="false" ID="a245if5be4183jh519jh4ab8cij3d9"
    IsPassive="false" IssueInstant="2016-03-19T16:59:09.534Z"
    ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
    Version="2.0" xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol">
    <saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">https://my-application.com/</saml2:Issuer>
</saml2p:AuthnRequest>

16:59:09.545 [ajp-bio-8009-exec-1] DEBUG o.o.w.m.encoder.BaseMessageEncoder - Successfully encoded message.
16:59:09.545 [ajp-bio-8009-exec-1] DEBUG o.s.s.s.storage.HttpSessionStorage - Storing message a245if5be4183jh519jh4ab8cij3d9 to session 0AFFA9527C8EEF8479BFCB6AE6655D3B
16:59:09.545 [ajp-bio-8009-exec-1] INFO  o.s.s.saml.log.SAMLDefaultLogger - AuthNRequest;SUCCESS;127.0.0.1;https://my-application.com/;https://default-idp.com/sso/idp/SAML2;;;
Thanks in advance.
Upvotes: 2
Answers (2)

vdenotaris
Reputation: 13637
As far as you obtained:
16:59:09.545 [ajp-bio-8009-exec-1] INFO o.s.s.saml.log.SAMLDefaultLogger - AuthNRequest;SUCCESS;127.0.0.1;https://my-application.com/;https://default-idp.com/sso/idp/SAML2
the AuthN process on the IdP-side has been completed.
Generally, there are two main cases:
there is an error in your implementation of SAMLUserDetailsService interface. In particular, check if the list of authorities for the instance of org.springframework.security.core.userdetails.User (returned by the method loadUserBySAML) contains at least one org.springframework.security.core.GrantedAuthority, properly configured according to your role model.
there is an unexpected behavior while executing the filter chain, thus the security context is cleaned right after the authentication process (i.e., Spring Security on Wildfly / Undertow: error executing the filter chain).
If your issue doesn't belong to those two cases, please provide a more verbose log to better point out the cause of the infinite loop.
Upvotes: 4
meetarun
Reputation: 569
make sure you import trust of your IDP in SP machines, and alos make sure SP and IDP in same time , we faced a similar issue and an system restart of IDP and SP has solved the issue.
Upvotes: 0
Infinite loop for SAML request in spring-saml

Answers (2)

Related Questions
