search

Internet2 / Shibboleth-Multi-Context-Broker

Shibboleth Multi-context Broker
4 stars 8 forks source link

No prompt for stronger authentication if initial context "good enough" for first SP #19

Open dhwalker opened 9 years ago

dhwalker commented 9 years ago

Subject: Re: [shib-assure] 1.2.2 testing -- good news and, possibly bad news? Date: Fri, 13 Feb 2015 08:37:04 -0800 From: David Walker dhwprof@gmail.com To: shib-assure@internet2.edu

Keith,

Chiming in... I also remember discussion of this issue. I think the general principle is that the configured initial authentication context should be handled separate from the incoming request from the SP, making behavior for the first SP and the second SP the same (the second SP exhibiting the correct behavior here). I looked at our Github issue list, and I don't see this one there, however, so I'll add it.

...

David

On 02/12/2015 10:26 AM, Wessel, Keith wrote: ... However, and I don’t know if this has been tackled yet, we still have the problem with the initial context being “good enough” and the MCB stopping there. To reiterate this issue:

Configure the IDP to have Password and Duo. Configure password as the only initial context since one can’t Duo auth until we know their principal.

With no session, go to an SP that accepts DUO then Password, in that order.

MCB prompts for password, user successfully authenticates.

Rather than giving the option of stepping up to Duo or even requiring it, user gets sent back to SP with Password.

If the SP described above is the 2nd SP the user visits in the session and the user already has satisfied Password from their 1st SP authentication, the MCB will allow for stepping up to Duo or possibly require it depending on configuration. It’s a different user experience, and it provides for functionality (stepping up) different than the 1st scenario above.

I recall agreeing that the scenario should be the same whether the session already existed or was newly created. It’s possible this was already fixed and I’m missing a configuration item. Can someone chime in here and help me out?

Keith

paulhethmon commented 9 years ago

Fixed in version 1.2.3 version of mcb.

paulhethmon commented 9 years ago

New version uploaded to fix bug when no context is requested. Still version 1.2.3 but dated 26 March 2015

dhwalker commented 9 years ago

Reported by Keith Wessel on 3/31/2015...

-------- Forwarded Message -------- Subject: RE: [shib-assure] mcb initial authentication (issue 19) Date: Tue, 31 Mar 2015 21:35:21 +0000 From: Wessel, Keith kwessel@illinois.edu Reply-To: shib-assure@internet2.edu To: shib-assure@internet2.edu shib-assure@internet2.edu

Paul,

So close!

When my user is allowed both password and duo and the service requests both, whether it's the first service I log into or the second, the IDP works perfectly. With showSatisfied set to true, I have a chance to proceed with password or upgrade to Duo when the service requests both. With it set to false, it forces me to upgrade. This latter behavior is exactly what we want.

Where I run into problems is when I take away the user's duo privileges. I remove the duo context from the user's IDM assurance attribute but leave both Duo and Password requested from the SP. I'm getting an error from the IDP that it can't satisfy any of the requested contexts even though password is allowed for this user. I'll include a log snippet below.

If I remove Duo from the requested contexts from the SP, I get in just fine with password. So, I don't think this is a misconfiguration. I haven't ruled that out, but I suspect a small bug.

Detailed logs are below. Thoughts?

Keith

16:30:03.603 - INFO [Shibboleth-Access:73] [session=] - 20150331T213003Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:03.735 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:92] [session=] - MCBConfiguration bean = [edu.internet2.middleware.assurance.mcb.authn.provider.MCBConfiguration@192705a7] 16:30:03.743 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:106] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:03.744 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:280] [session=] - Redirecting to https://shib-test-idp.cites.illinois.edu:443/idp/Authn/MCB 16:30:03.821 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:120] [session=] - Request received from [130.126.153.244] 16:30:03.821 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:124] [session=] - Creating new principal object for request. 16:30:03.823 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:128] [session=] - principal = [{MCBUsernamePrincipal}[principal]] 16:30:03.824 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:137] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:03.824 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:180] [session=] - Selected method name = [null] 16:30:03.824 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:193] [session=] - Either first leg or bad method selected. Going to show methods. 16:30:03.825 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:531] [session=] - Showing methods available based on configuration. 16:30:03.825 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:601] [session=] - Showing only default contexts from configuration. 16:30:03.825 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:608] [session=] - Using submodule with bean name of [mcb.usernamepassword] 16:30:03.826 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.JAASLoginSubmodule:119] [session=] - Displaying Velocity password login template [jaaslogin.vm] 16:30:03.830 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.ui.IDPUIHandler:65] [session=] - target language is en 16:30:03.831 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.ui.IDPUIHandler:122] [session=] - SPEntity is https://shib-sp-dev.cites.illinois.edu/shibboleth 16:30:03.832 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.ui.IDPUIHandler:96] [session=] - no UI info in EntityDescriptor https://shib-sp-dev.cites.illinois.edu/shibboleth 16:30:03.832 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.ui.IDPUIHandler:122] [session=] - SPEntity is https://shib-sp-dev.cites.illinois.edu/shibboleth 16:30:03.833 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.ui.IDPUIHandler:122] [session=] - SPEntity is https://shib-sp-dev.cites.illinois.edu/shibboleth 16:30:03.833 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:850] [session=] - Displaying velocity template of [jaaslogin.vm] 16:30:03.864 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:618] [session=] - submodule returned [true] 16:30:11.297 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:120] [session=] - Request received from [130.126.153.244] 16:30:11.297 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:128] [session=] - principal = [{MCBUsernamePrincipal}[principal]] 16:30:11.300 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:137] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:11.300 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:170] [session=] - Performing authentication for request. 16:30:11.300 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:207] [session=] - Found 2nd leg of authentication, performing authentication. 16:30:11.301 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:806] [session=] - Getting requested contexts for relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:11.302 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.JAASLoginSubmodule:244] [session=] - Attempting to authenticate user kwessel 16:30:11.495 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.JAASLoginSubmodule:252] [session=] - Successfully authenticated user kwessel 16:30:11.498 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:223] [session=] - submodule process login returned [true] 16:30:11.499 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:256] [session=] - Running attribute resolution for principal [kwessel] 16:30:11.499 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:67] [session=] - Performing attribute resolution for kwessel 16:30:11.969 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uid] 16:30:11.970 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uid 16:30:11.970 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uid Value = kwessel

16:30:11.971 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [homeOrganizationType] 16:30:11.971 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - homeOrganizationType 16:30:11.971 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = homeOrganizationType Value = university

16:30:11.971 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonAffiliation] 16:30:11.971 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonAffiliation 16:30:11.972 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonAffiliation Value = member Value = staff Value = employee

16:30:11.972 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonPrincipalName] 16:30:11.972 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonPrincipalName 16:30:11.972 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonPrincipalName Value = kwessel

16:30:11.972 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonPrimaryAffiliation] 16:30:11.973 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonPrimaryAffiliation 16:30:11.973 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonPrimaryAffiliation Value = staff

16:30:11.973 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [assurance] 16:30:11.973 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - assurance 16:30:11.973 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = assurance Value = urn:oasis:names:tc:SAML:2.0:ac:classes:Password Value = http://id.incommon.org/assurance/bronze Value = http://id.incommon.org/assurance/silver

16:30:11.974 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [gIllinoisID] 16:30:11.974 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - gIllinoisID 16:30:11.979 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = gIllinoisID Value = kwessel@illinois.edu

16:30:11.979 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduNetID] 16:30:11.979 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduNetID 16:30:11.979 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduNetID Value = kwessel

16:30:11.979 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [gIllinoisIDTemplate] 16:30:11.980 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - gIllinoisIDTemplate 16:30:11.980 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = gIllinoisIDTemplate Value = kwessel@illinois.edu

16:30:11.980 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [organizationName] 16:30:11.980 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - organizationName 16:30:11.980 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = organizationName Value = University of Illinois at Urbana-Champaign

16:30:11.981 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduADGroups] 16:30:11.981 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduADGroups 16:30:11.981 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduADGroups Value = CN=UIUC Campus Accounts,OU=People,DC=addev,DC=uillinois,DC=edu Value = CN=SDG-Testers,OU=SDG-People,OU=CITES-SDG,OU=CITES-Services,OU=CITES,OU=Urbana,DC=addev,DC=uillinois,DC=edu

16:30:11.981 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonScopedAffiliation] 16:30:11.982 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonScopedAffiliation 16:30:11.982 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonScopedAffiliation Value = member Value = staff Value = employee

16:30:11.982 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [givenName] 16:30:11.982 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - givenName 16:30:11.982 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = givenName Value = Keith

16:30:11.983 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonNickname] 16:30:11.983 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonNickname 16:30:11.983 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonNickname Value = kwessel Value = geeber Value = quessel

16:30:11.983 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [googleAppsID] 16:30:11.983 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - googleAppsID 16:30:11.984 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = googleAppsID Value = kwessel@gmailtest.illinois.edu

16:30:11.984 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [title] 16:30:11.989 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - title 16:30:11.989 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = title Value = APPLICATION INTEGRATION PRO

16:30:11.989 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduHomeDeptName] 16:30:11.989 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduHomeDeptName 16:30:11.990 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduHomeDeptName Value = CITES

16:30:11.990 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduSource] 16:30:11.990 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduSource 16:30:11.990 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduSource Value = edw-demo Value = edw-job Value = edw-employee Value = edw-address Value = edw-telephone Value = payroll

16:30:11.990 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonOrgDN] 16:30:11.991 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonOrgDN 16:30:11.991 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonOrgDN Value = o=University of Illinois at Urbana-Champaign,dc=uiuc,dc=edu

16:30:11.991 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [principal] 16:30:11.991 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - principal 16:30:11.991 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = principal Value = kwessel

16:30:11.992 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [gTestIllinoisIDTemplate] 16:30:11.992 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - gTestIllinoisIDTemplate 16:30:11.992 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = gTestIllinoisIDTemplate Value = kwessel@g-test.illinois.edu

16:30:11.992 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [googleAppsIDTemplate] 16:30:11.993 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - googleAppsIDTemplate 16:30:11.993 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = googleAppsIDTemplate Value = kwessel@gmailtest.illinois.edu

16:30:11.993 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [sAMAccountName] 16:30:11.993 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - sAMAccountName 16:30:11.993 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = sAMAccountName Value = kwessel

16:30:11.994 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduMiddleName] 16:30:11.994 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduMiddleName 16:30:11.994 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduMiddleName Value = William

16:30:12.001 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonEntitlement] 16:30:12.001 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonEntitlement 16:30:12.001 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonEntitlement Value = urn:mace:dir:entitlement:common-lib-terms

16:30:12.001 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [organizationalUnit] 16:30:12.001 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - organizationalUnit 16:30:12.002 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = organizationalUnit Value = CITES

16:30:12.002 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [mail] 16:30:12.002 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - mail 16:30:12.002 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = mail Value = kwessel@illinois.edu

16:30:12.002 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [sn] 16:30:12.003 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - sn 16:30:12.003 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = sn Value = Wessel

16:30:12.003 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [gTestIllinoisID] 16:30:12.003 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - gTestIllinoisID 16:30:12.004 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = gTestIllinoisID Value = kwessel@g-test.illinois.edu

16:30:12.004 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [transientId] 16:30:12.004 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - transientId 16:30:12.004 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = transientId Value = _e7681868e5af31c0726c3ac41f25e956

16:30:12.004 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduLastName] 16:30:12.005 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduLastName 16:30:12.005 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduLastName Value = Wessel

16:30:12.005 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [iTrustMiddleName] 16:30:12.005 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - iTrustMiddleName 16:30:12.006 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = iTrustMiddleName Value = William

16:30:12.006 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduFirstName] 16:30:12.006 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduFirstName 16:30:12.014 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduFirstName Value = Keith

16:30:12.015 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [eduPersonTargetedID] 16:30:12.015 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - eduPersonTargetedID 16:30:12.015 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = eduPersonTargetedID Value = org.opensaml.saml2.core.impl.NameIDImpl@2f18de2

16:30:12.015 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [isMemberOf] 16:30:12.016 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - isMemberOf 16:30:12.016 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = isMemberOf Value = urn:mace:uiuc.edu:people:uiuc campus accounts Value = urn:mace:uiuc.edu:urbana:cites:cites-services:cites-sdg:sdg-people:sdg-testers

16:30:12.016 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduType] 16:30:12.016 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduType 16:30:12.016 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduType Value = staff Value = phone Value = person

16:30:12.017 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [telephoneNumber] 16:30:12.017 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - telephoneNumber 16:30:12.017 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = telephoneNumber Value = +1 217 265 0313

16:30:12.017 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [postalAddress] 16:30:12.017 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - postalAddress 16:30:12.018 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = postalAddress Value = Cites

1128 Dcl

1304 W Springfield

M/C 256

Urbana, IL 61801

16:30:12.018 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [regex_principal_split] 16:30:12.018 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - regex_principal_split 16:30:12.018 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = regex_principal_split Value = kwessel

16:30:12.018 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [iTrustAffiliation] 16:30:12.019 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - iTrustAffiliation 16:30:12.024 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = iTrustAffiliation Value = staff Value = phone Value = person

16:30:12.025 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [iTrustUIN] 16:30:12.025 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - iTrustUIN 16:30:12.025 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = iTrustUIN Value = 653818502

16:30:12.025 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [uiucEduUIN] 16:30:12.025 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - uiucEduUIN 16:30:12.026 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = uiucEduUIN Value = 653818502

16:30:12.026 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:78] [session=] - Attribute key = [displayName] 16:30:12.026 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:79] [session=] - displayName 16:30:12.026 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBAttributeResolver:93] [session=] - ID = displayName Value = Keith William Wessel

16:30:12.027 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:261] [session=] - Found idms attribute: assurance 16:30:12.027 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:263] [session=] - Found [3] values in attribute. 16:30:12.027 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:271] [session=] - User authenticated with method [password] 16:30:12.027 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:302] [session=] - Used context listed in valid contexts = [true] 16:30:12.028 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:311] [session=] - Used context for principal [kwessel] is on the potential allowed list. 16:30:12.028 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:314] [session=] - requestedContexts = [2] 16:30:12.028 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:316] [session=] - rc = [urn:mace:uiuc.edu:authn:duo] 16:30:12.028 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:316] [session=] - rc = [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:12.029 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:319] [session=] - validContexts = [6] 16:30:12.029 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [urn:mace:uiuc.edu:authn:duo] 16:30:12.029 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:12.029 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [http://id.incommon.org/assurance/bronze] 16:30:12.029 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [http://id.incommon.org/assurance/silver] 16:30:12.030 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [http://id.incommon.org/assurance/silver-token] 16:30:12.030 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:321] [session=] - vc = [edu:internet2:middleware:assurance:mcb:tokenpluspin] 16:30:12.030 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:324] [session=] - Used context listed in requested contexts = [true] 16:30:12.030 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:342] [session=] - Adding context [urn:mace:uiuc.edu:authn:duo} to the missing list 16:30:12.030 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:338] [session=] - Adding context [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] to matched list. 16:30:12.031 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:378] [session=] - Principal [kwessel] must authenticate with a different context. 16:30:12.031 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:664] [session=] - Force reauth = [false] 16:30:12.031 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:668] [session=] - Found [1] allowable contexts to choose from. 16:30:12.031 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:679] [session=] - Found previously satisfied context of [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:12.032 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:690] [session=] - Skipping method [Username/Password Only] due to excluding already satisfied context values. 16:30:12.032 - WARN [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:716] [session=] - Unable to satisfy requested authentication context of [[urn:mace:uiuc.edu:authn:duo, urn:oasis:names:tc:SAML:2.0:ac:classes:Password]]. Returning SAML error to SP. 16:30:12.044 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:172] [session=] - Authentication result = [false] 16:30:12.118 - INFO [Shibboleth-Access:73] [session=] - 20150331T213012Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:12.285 - INFO [Shibboleth-Audit:1028] [session=] - 20150331T213012Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|_60a316660a396eb231e9ab9f0751a376|https://shib-sp-dev.cites.illinois.edu/shibboleth|urn:mace:shibboleth:2.0:profiles:saml2:sso|urn:mace:incommon:test.uiuc.edu|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_f1cbe4dd5315d4326e0acf770870cb2e|||||| 16:30:12.917 - INFO [Shibboleth-Access:73] [session=] - 20150331T213012Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:12.981 - INFO [Shibboleth-Access:73] [session=] - 20150331T213012Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:13.045 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:92] [session=] - MCBConfiguration bean = [edu.internet2.middleware.assurance.mcb.authn.provider.MCBConfiguration@192705a7] 16:30:13.046 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:106] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.047 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:280] [session=] - Redirecting to https://shib-test-idp.cites.illinois.edu:443/idp/Authn/MCB 16:30:13.052 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:92] [session=] - MCBConfiguration bean = [edu.internet2.middleware.assurance.mcb.authn.provider.MCBConfiguration@192705a7] 16:30:13.053 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:106] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.053 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginHandler:280] [session=] - Redirecting to https://shib-test-idp.cites.illinois.edu:443/idp/Authn/MCB 16:30:13.135 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:120] [session=] - Request received from [130.126.153.244] 16:30:13.135 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:128] [session=] - principal = [{MCBUsernamePrincipal}kwessel] 16:30:13.136 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:137] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.137 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:148] [session=] - Performing authentication upgrade for request. 16:30:13.137 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:806] [session=] - Getting requested contexts for relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.138 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:664] [session=] - Force reauth = [false] 16:30:13.138 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:668] [session=] - Found [1] allowable contexts to choose from. 16:30:13.138 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:679] [session=] - Found previously satisfied context of [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:13.138 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:690] [session=] - Skipping method [Username/Password Only] due to excluding already satisfied context values. 16:30:13.139 - WARN [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:716] [session=] - Unable to satisfy requested authentication context of [[urn:mace:uiuc.edu:authn:duo, urn:oasis:names:tc:SAML:2.0:ac:classes:Password]]. Returning SAML error to SP. 16:30:13.248 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:120] [session=] - Request received from [130.126.153.244] 16:30:13.249 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:128] [session=] - principal = [{MCBUsernamePrincipal}kwessel] 16:30:13.250 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:137] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.250 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:148] [session=] - Performing authentication upgrade for request. 16:30:13.251 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:806] [session=] - Getting requested contexts for relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.252 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:664] [session=] - Force reauth = [false] 16:30:13.252 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:120] [session=] - Request received from [130.126.153.244] 16:30:13.252 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:668] [session=] - Found [1] allowable contexts to choose from. 16:30:13.252 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:128] [session=] - principal = [{MCBUsernamePrincipal}kwessel] 16:30:13.252 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:679] [session=] - Found previously satisfied context of [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:13.253 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:690] [session=] - Skipping method [Username/Password Only] due to excluding already satisfied context values. 16:30:13.253 - WARN [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:716] [session=] - Unable to satisfy requested authentication context of [[urn:mace:uiuc.edu:authn:duo, urn:oasis:names:tc:SAML:2.0:ac:classes:Password]]. Returning SAML error to SP. 16:30:13.253 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:137] [session=] - Relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.254 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:148] [session=] - Performing authentication upgrade for request. 16:30:13.254 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:806] [session=] - Getting requested contexts for relying party = [https://shib-sp-dev.cites.illinois.edu/shibboleth] 16:30:13.255 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:664] [session=] - Force reauth = [false] 16:30:13.255 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:668] [session=] - Found [1] allowable contexts to choose from. 16:30:13.255 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:679] [session=] - Found previously satisfied context of [urn:oasis:names:tc:SAML:2.0:ac:classes:Password] 16:30:13.256 - DEBUG [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:690] [session=] - Skipping method [Username/Password Only] due to excluding already satisfied context values. 16:30:13.256 - WARN [edu.internet2.middleware.assurance.mcb.authn.provider.MCBLoginServlet:716] [session=] - Unable to satisfy requested authentication context of [[urn:mace:uiuc.edu:authn:duo, urn:oasis:names:tc:SAML:2.0:ac:classes:Password]]. Returning SAML error to SP. 16:30:13.357 - INFO [Shibboleth-Access:73] [session=] - 20150331T213013Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:13.360 - INFO [Shibboleth-Access:73] [session=] - 20150331T213013Z|130.126.153.244|shib-test-idp.cites.illinois.edu:443|/profile/SAML2/Redirect/SSO| 16:30:13.371 - WARN [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:400] [session=] - Error decoding authentication request message org.opensaml.ws.message.decoder.MessageDecodingException: No SAMLRequest or SAMLResponse query path parameter, invalid SAML 2 HTTP Redirect message at org.opensaml.saml2.binding.decoding.HTTPRedirectDeflateDecoder.doDecode(HTTPRedirectDeflateDecoder.java:98) ~[opensaml-2.6.3.jar:na] at org.opensaml.ws.message.decoder.BaseMessageDecoder.decode(BaseMessageDecoder.java:79) ~[openws-1.5.3.jar:na] at org.opensaml.saml2.binding.decoding.BaseSAML2MessageDecoder.decode(BaseSAML2MessageDecoder.java:70) ~[opensaml-2.6.3.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.decodeRequest(SSOProfileHandler.java:386) [shibboleth-identityprovider-2.4.2.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.performAuthentication(SSOProfileHandler.java:211) [shibboleth-identityprovider-2.4.2.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:189) [shibboleth-identityprovider-2.4.2.jar:na] at edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler.processRequest(SSOProfileHandler.java:90) [shibboleth-identityprovider-2.4.2.jar:na] at edu.internet2.middleware.shibboleth.common.profile.ProfileRequestDispatcherServlet.service(ProfileRequestDispatcherServlet.java:83) [shibboleth-common-1.4.2.jar:na] at javax.servlet.http.HttpServlet.service(HttpServlet.java:723) [servlet-api.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.jar:6.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41] at net.clareitysecurity.shibboleth.storage.ClusterFilter.doFilter(ClusterFilter.java:95) [db-storage-service-1.1.3.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41] at edu.internet2.middleware.shibboleth.idp.util.NoCacheFilter.doFilter(NoCacheFilter.java:50) [shibboleth-identityprovider-2.4.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41] at edu.internet2.middleware.shibboleth.idp.session.IdPSessionFilter.doFilter(IdPSessionFilter.java:87) [shibboleth-identityprovider-2.4.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41] at edu.internet2.middleware.shibboleth.common.log.SLF4JMDCCleanupFilter.doFilter(SLF4JMDCCleanupFilter.java:52) [shibboleth-common-1.4.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [catalina.jar:6.0.41] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.41] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:6.0.41] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.41] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.41] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:6.0.41] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.41] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina.jar:6.0.41] at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190) [tomcat-coyote.jar:6.0.41] at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311) [tomcat-coyote.jar:6.0.41] at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776) [tomcat-coyote.jar:6.0.41] at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705) [tomcat-coyote.jar:6.0.41] at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898) [tomcat-coyote.jar:6.0.41] at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690) [tomcat-coyote.jar:6.0.41] at java.lang.Thread.run(Thread.java:745) [na:1.7.0_60] 16:30:13.393 - INFO [Shibboleth-Audit:1028] [session=] - 20150331T213013Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|_3ec8ad49e67f5ee98888a0a6abedb515|https://shib-sp-dev.cites.illinois.edu/shibboleth|urn:mace:shibboleth:2.0:profiles:saml2:sso|urn:mace:incommon:test.uiuc.edu|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_9a124b9c15bb7c3dde64843fe3c790fb||||||

paulhethmon commented 9 years ago

Build 1.2.5 has been put into github to fix this issue. I am not positive I am handling all of the cases correctly that are possible. The code has gotten to the point where it likely needs to be rewritten to satisfy all the possibilities instead of the tweaks that have been done so far. But maybe it will work for everything.