-
Type:
Bug
-
Status: Closed
-
Priority:
Blocker
-
Resolution: Fixed
-
Affects Version/s: 3.1.2
-
Component/s: Authentication, CAS, Relying Party
-
Labels:None
-
Environment:
My desktop dev env. is Ubuntu 14.04
Server env. is FreeBSD linux
Both are running IdPv3.1.2 on Jetty 9.3.2.v20150730
Please find SP metadata.xml attached, as requested...
From the email thread on users@shibboleth.net:
I ran the same test login scenario against an OOB implementation of IdP3 with CAS protocol enabled; restart jetty, login/logout from a SAML2 SP, try CAS service login. Sorry to report same results. I am including a similar idp-process.log excerpt from this test run.
One point of interest… I wanted to check out the source for the class that is referenced in this log entry:
2015-11-03 10:12:24,760 - DEBUG [net.shibboleth.idp.cas.flow.BuildRelyingPartyContextAction:83] - Setting up RP context for verified relying party http://10.10.18.162:7080/cas-sample/j_spring_cas_security_check
… the source repo has the class BuildRelyingPartyContextAction in a different package, net.shibboleth.idp.cas.flow.impl. Maybe I am not browsing the repo correctly?
Anyway, here is the most recent log excerpt:
2015-11-03 10:12:21,214 - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:602] - Loading SPSession for service http://wts-staging1.ito.umt.edu/Shibboleth.sso in session 24bf133b7cba7a11f39b57176ab0eeaaafff9f244886a2d0de59bb9fbbc5639b
2015-11-03 10:12:21,214 - DEBUG [net.shibboleth.idp.session.SPSessionSerializerRegistry:86] - Registry located StorageSerializer of type 'net.shibboleth.idp.saml.session.impl.SAML2SPSessionSerializer' for SPSession type 'class net.shibboleth.idp.saml.session.SAML2SPSession'
2015-11-03 10:12:21,216 - DEBUG [net.shibboleth.idp.saml.saml2.profile.impl.ProcessLogoutRequest:272] - Profile Action ProcessLogoutRequest: LogoutRequest matches IdP session 24bf133b7cba7a11f39b57176ab0eeaaafff9f244886a2d0de59bb9fbbc5639b
2015-11-03 10:12:21,216 - DEBUG [net.shibboleth.idp.session.impl.StorageBackedSessionManager:521] - Destroyed session 24bf133b7cba7a11f39b57176ab0eeaaafff9f244886a2d0de59bb9fbbc5639b
2015-11-03 10:12:21,219 - DEBUG [net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] - Profile Action PopulateAuditContext: Adding 1 value for field 'u'
2015-11-03 10:12:21,219 - DEBUG [net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:220] - Profile Action PopulateAuditContext: Adding 1 value for field 'n'
2015-11-03 10:12:21,219 - DEBUG [net.shibboleth.idp.profile.audit.impl.PopulateAuditContext:198] - Profile Action PopulateAuditContext: Skipping field 's' not included in audit format
2015-11-03 10:12:21,229 - ERROR [org.apache.velocity:96] - ResourceManager : unable to find resource 'logout.vm' in any resource loader.
2015-11-03 10:12:24,760 - DEBUG [net.shibboleth.idp.session.impl.PopulateSessionContext:131] - Profile Action PopulateSessionContext: No session found for client
2015-11-03 10:12:24,760 - DEBUG [net.shibboleth.idp.cas.service.PatternServiceRegistry:60] - Evaluating whether http://10.10.18.162:7080/cas-sample/j_spring_cas_security_check matches ^(http|https)://.*?
2015-11-03 10:12:24,760 - DEBUG [net.shibboleth.idp.cas.service.PatternServiceRegistry:62] - Found match
2015-11-03 10:12:24,760 - DEBUG [net.shibboleth.idp.cas.flow.BuildRelyingPartyContextAction:83] - Setting up RP context for verified relying party http://10.10.18.162:7080/cas-sample/j_spring_cas_security_check
2015-11-03 10:12:24,761 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:284] - Resolving relying party configuration
2015-11-03 10:12:24,761 - DEBUG [net.shibboleth.idp.relyingparty.impl.DefaultRelyingPartyConfigurationResolver:305] - No relying party configurations are applicable, returning the default configuration shibboleth.DefaultRelyingParty
2015-11-03 10:12:24,761 - DEBUG [net.shibboleth.idp.profile.impl.SelectRelyingPartyConfiguration:136] - Profile Action SelectRelyingPartyConfiguration: Found relying party configuration shibboleth.DefaultRelyingParty for request
2015-11-03 10:12:24,762 - DEBUG [net.shibboleth.idp.cas.flow.CheckAuthenticationRequiredAction:82] - IdP session not found
2015-11-03 10:12:24,762 - DEBUG [net.shibboleth.idp.authn.impl.PopulateAuthenticationContext:125] - Profile Action PopulateAuthenticationContext: Installing custom PrincipalEvalPredicateFactoryRegistry into AuthenticationContext
2015-11-03 10:12:24,763 - DEBUG [net.shibboleth.idp.authn.impl.PopulateAuthenticationContext:158] - Profile Action PopulateAuthenticationContext: Installed 1 authentication flows into AuthenticationContext
2015-11-03 10:12:24,763 - DEBUG [net.shibboleth.idp.session.impl.PopulateSessionContext:131] - Profile Action PopulateSessionContext: No session found for client
2015-11-03 10:12:24,763 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByForcedAuthn:53] - Profile Action FilterFlowsByForcedAuthn: Request does not have forced authentication requirement, nothing to do
2015-11-03 10:12:24,764 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByPassivity:53] - Profile Action FilterFlowsByPassivity: Request does not have passive requirement, nothing to do
2015-11-03 10:12:24,764 - DEBUG [net.shibboleth.idp.authn.impl.FilterFlowsByNonBrowserSupport:53] - Profile Action FilterFlowsByNonBrowserSupport: Request does not have non-browser requirement, nothing to do
2015-11-03 10:12:24,764 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:241] - Profile Action SelectAuthenticationFlow: No specific Principals requested
2015-11-03 10:12:24,764 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:267] - Profile Action SelectAuthenticationFlow: No usable active results available, selecting an inactive flow
2015-11-03 10:12:24,764 - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:309] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/Password
2015-11-03 10:12:24,765 - DEBUG [net.shibboleth.idp.authn.impl.ExtractUsernamePasswordFromBasicAuth:115] - Profile Action ExtractUsernamePasswordFromBasicAuth: No appropriate Authorization header found
2015-11-03 10:12:24,773 - DEBUG [net.shibboleth.idp.ui.context.RelyingPartyUIContext:744] - Returning logo from UIInfo, 'en' (150 x 150) : https://www.umt.edu/templates/imx/idp_logo_test.png
2015-11-03 10:12:24,774 - DEBUG [net.shibboleth.idp.ui.context.RelyingPartyUIContext:264] - Acceptable Scheme 'https', returning value 'https://www.umt.edu/templates/imx/idp_logo_test.png'
2015-11-03 10:12:24,775 - DEBUG [net.shibboleth.idp.ui.context.RelyingPartyUIContext:310] - Returning name from UIInfo 'Staging 1 SP'
2015-11-03 10:12:24,775 - DEBUG [net.shibboleth.idp.ui.context.RelyingPartyUIContext:551] - Returning OrganizationDisplayName from Organization, University of Montana, WTS-Staging1