Infrastructure at your Service

Morgan Patou

WebLogic – SSO/Atn/Atz – Infinite loop

This blog will be the last of my series around the WebLogic SSO (how to enable logs, 403 N°1, 403 N°2) which I started some weeks ago. Several months ago on a newly built High Availability Environment (2 WebLogic Servers behind a Load Balancer), an application team was deploying their D2 Client as always. After the deployment, it appeared to the tester that the Single Sign-On was not working when using the SSO URL through the Load Balancer. For this user, the URL was going crazy on an infinite loop between the LB URL and the SAML2 Partner URL. When I tried to replicate the issue, the SSO was working fine for me…

The only possible reason for the infinite loop for some users but not for all is that there is an issue with the SSO setup/configuration on one of the two WebLogic Servers only… Indeed, the Load Balancer (with sticky session) probably redirected the tester on the WLS with the issue while my session was redirected to the other one. Enabling the debug logs (on both WLS) quickly confirmed that all communications that were going through the first WebLogic Server were working properly (with SSO) while the second WebLogic Server had this infinite loop issue.

The logs from the WebLogic Server 1 and 2 were identical up to a certain point (basically all the SAML2 part), except some elements such as the local hostname, the date/hour and some IDs (like java class instances, aso…). This is the common content on both WLS logs:

<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <SAML2Filter: Processing request on URI '/D2/X3_Portal.jsp'>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is '/D2/X3_Portal.jsp'>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is not a service URI>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): returning service type 'SPinitiator'>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: processing>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: partner id is null>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: use partner binding HTTP/POST>
<Nov 21, 2017 9:25:39 AM UTC> <Debug> <SecuritySAML2Service> <post from template url: null>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <SAML2Servlet: Processing request on URI '/saml2/sp/acs/post'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is '/saml2/sp/acs/post'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): service URI is '/sp/acs/post'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): returning service type 'ACS'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <Assertion consumer service: processing>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <get SAMLResponse from http request:PBvbnNSJ1cXMlFtZzaXM6bmHhtbG5zm46NhwOlJlOnNhbWxHbWxIb2Fc3wP6dGM6
U0FiB4bWxuczp4NTAwPSJ1cm46b2FzNTDoyLjA6YXNzZXJ0aW9uIaXM6bmFtZXM6
U0FdG9jb2wiIHhtbG5zOmRzaWc9Imh0dHA6Ly93NTDoyLjA6cHJvd3cudzMub3Jn
aHR0cDoa5vcmcvMjAwMS9W5zdGFuY2vL3d3dy53MyYTUxTY2hlbWEtUiIERlc3Rp
MWNxM2FjNzI1ZDjYmIVhNDM1Zlzc3VlSW5zdGFudD0ijhlNjc3OTkiIEMjAxNy0x
LzINpZyMiIHhtwMDAvMDkveG1sZHbG5DovL3d3dy53My5vczOmVuYz0iaHR0cmcv
...
YWRpb24+P1sOkF1ZGllbHJpY3mPHNhNlUmVzdC9zYW1sOkNvbmRpdGlvbnM+bWw6
YXNzUzpjbYW1YXNpczpuIuMlmVmPnVybjpvDphYxzp0YzpTQU1MOjGFzc2VzOlBh
OjAXh0Pj0OjUyWiI+PHNsOkF1dGhuQhxzYW129udGV4bWw6QXV0aG5Db250ZdENs
UmVnRlepBdXRobkNvbzYWmPjwvc2FtbDF1dGhuU1sOkHQ+PC93RhdGVtZW50Pjwv
c2F9zY25zZtbDpBcW1scDpSZXNwb3NlcnRpb24+PCT4=
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <BASE64 decoded saml message:<samlp:Response xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:dsig="http://www.w3.org/2000/09/xmldsig#" xmlns:enc="http://www.w3.org/2001/04/xmlenc#" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:x500="urn:oasis:names:tc:SAML:2.0:profiles:attribute:X500" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" Destination="https://weblogic_server_01/saml2/sp/acs/post" ID="id-HpDtn7r5XxxAQFYnwSLXZmkuVgIHTExrlreEDZ4-" InResponseTo="_0x7258edc52961ccbd5a435fb13ac67799" IssueInstant="2017-11-21T9:25:55Z" Version="2.0"><saml:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">https://idp_partner_01/fed/idp</saml:Issuer><dsig:Signature><dsig:SignedInfo><dsig:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><dsig:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/><dsig:Reference URI="#id-HpDtn7r5XxxAQFYnwSLXZmkuVgIHTExrlreEDZ4-"><dsig:Transforms><dsig:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><dsig:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/></dsig:Transforms><dsig:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/><dsig:DigestValue>YGtUZvsfo3z51AsBo7UDhbd6Ts=</dsig:DigestValue></dsig:Reference></dsig:SignedInfo><dsig:SignatureValue>al8sJwbqzjh1qgM3Sj0QrX1aZjwyI...JB6l4jmj91BdQrYQ7VxFzvNLczZ2brJSdLLig==</dsig:SignatureValue><dsig:KeyInfo><dsig:X509Data><dsig:X509Certificate>MIwDQUg+nhYqGZ7pCgBQAwTTELMAkGA1UEBhMCQk1ZhQ...aATPRCd113tVqsvCkUwpfQ5zyUHaKw4FkXmiT2nzxxHA==</dsig:X509Certificate></dsig:X509Data></dsig:KeyInfo></dsig:Signature><samlp:Status><samlp:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:Success"/></samlp:Status><saml:Assertion ID="id-0WrMNbOz6wsuZdFPhfjnw7WIXXQ6k89-1AgHZ9Oi" IssueInstant="2017-11-21T9:25:55Z" Version="2.0"><saml:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity">https://idp_partner_01/fed/idp</saml:Issuer><dsig:Signature><dsig:SignedInfo><dsig:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><dsig:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/><dsig:Reference URI="#id-0WrMNbOz6wsuZdFPhfjnw7WIXXQ6k89-1AgHZ9Oi"><dsig:Transforms><dsig:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><dsig:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/></dsig:Transforms><dsig:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/><dsig:DigestValue>7+jZtq8SpY3BKVaFjIFeEJm51cA=</dsig:DigestValue></dsig:Reference></dsig:SignedInfo><dsig:SignatureValue>GIlXt4B4rVFoDJRxidpZO73gXB68Dd+mcpoV9DKrjBBjLRz...zGTDcEYY2MG8FgtarZhVQGc4zxkkSg8GRT6Wng3NEuTUuA==</dsig:SignatureValue><dsig:KeyInfo><dsig:X509Data><dsig:X509Certificate>MIwDQUg+nhYqGZ7pCgBQAwTTELMAkGA1UEBhMCQk1ZhQ...aATPRCd113tVqsvCkUwpfQ5zyUHaKw4FkXmiT2nzxxHA==</dsig:X509Certificate></dsig:X509Data></dsig:KeyInfo></dsig:Signature><saml:Subject><saml:NameID Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified">PATOU_MORGAN</saml:NameID><saml:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer"><saml:SubjectConfirmationData InResponseTo="_0x7258edc52961ccbd5a435fb13ac67799" NotOnOrAfter="2017-11-21T9:30:55Z" Recipient="https://weblogic_server_01/saml2/sp/acs/post"/></saml:SubjectConfirmation></saml:Subject><saml:Conditions NotBefore="2017-11-21T9:25:55Z" NotOnOrAfter="2017-11-21T9:30:55Z"><saml:AudienceRestriction><saml:Audience>SAML2_Entity_ID_01</saml:Audience></saml:AudienceRestriction></saml:Conditions><saml:AuthnStatement AuthnInstant="2017-11-21T9:25:55Z" SessionIndex="id-oX9wXdpGmt9GQlVffvY4hEIRULEd25nrxDzE8D7w" SessionNotOnOrAfter="2017-11-21T9:40:55Z"><saml:AuthnContext><saml:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml:AuthnContextClassRef></saml:AuthnContext></saml:AuthnStatement></saml:Assertion></samlp:Response>>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <<samlp:Response> is signed.>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionServiceImpl.assertIdentity(SAML2.Assertion.DOM)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionTokenServiceImpl.assertIdentity(SAML2.Assertion.DOM)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2IdentityAsserterProvider: start assert SAML2 token>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2IdentityAsserterProvider: SAML2IdentityAsserter: tokenType is 'SAML2.Assertion.DOM'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: Start verify assertion signature>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: The assertion is signed.>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: End verify assertion signature>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: Start verify assertion attributes>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: End verify assertion attributes>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: Start verify assertion issuer>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: End verify assertion issuer>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: Start verify assertion conditions>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: End verify assertion conditions>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: Start verify assertion subject>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert: End verify assertion subject>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2NameMapperCache.getNameMapper: Found name mapper in the cache>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAML2Assert.processAttributes - processAttrs: false, processGrpAttrs: true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <DefaultSAML2NameMapperImpl: mapName: Mapped name: qualifier: null, name: PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAMLIACallbackHandler: SAMLIACallbackHandler(true, PATOU_MORGAN, null)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionCallbackServiceImpl.assertIdentity>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionCallbackServiceImpl.assertIdentity>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAMLIACallbackHandler: callback[0]: NameCallback: setName(PATOU_MORGAN)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionCallbackServiceImpl.assertIdentity returning PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityCacheServiceImpl.getCachedIdentity(idm:_def_Idmusr:PATOU_MORGAN)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityCacheServiceImpl.getCachedIdentity(idm:_def_Idmusr:PATOU_MORGAN) returning null>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityAssertionCallbackServiceImpl.assertIdentity did not find a cached identity.>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.constructor>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl.getJAASIdentityAssertionConfigurationName()>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <weblogic.security.service.internal.WLSJAASLoginServiceImpl$ServiceImpl.authenticate>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login ClassLoader=sun.misc.Launcher$AppClassLoader@7d4991ad>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login ThreadContext ClassLoader Original=com.bea.common.security.utils.SAML2ClassLoader@625ecb90>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl.getAppConfigurationEntry(com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl0)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl.getAppConfigurationEntry>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.legacy.service.JAASIdentityAssertionProviderImpl$V1Wrapper.getAssertionModuleConfiguration>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl$JAASProviderImpl.getProviderAppConfigurationEntry returning LoginModuleClassName=weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl, ControlFlag=LoginModuleControlFlag: sufficient>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.legacy.service.JAASIdentityAssertionProviderImpl$V1Wrapper.getClassLoader>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap LoginModuleClassName=weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap ClassLoader=java.net.URLClassLoader@108c7fe5>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap ControlFlag=LoginModuleControlFlag: sufficient>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.legacy.service.JAASIdentityAssertionProviderImpl$V1Wrapper.getAssertionModuleConfiguration>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASIdentityAssertionConfigurationServiceImpl$JAASProviderImpl.getProviderAppConfigurationEntry returning LoginModuleClassName=weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl, ControlFlag=LoginModuleControlFlag: required>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.legacy.service.JAASIdentityAssertionProviderImpl$V1Wrapper.getClassLoader>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap LoginModuleClassName=weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap ClassLoader=java.net.URLClassLoader@108c7fe5>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.wrap ControlFlag=LoginModuleControlFlag: required>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login created LoginContext>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login ThreadContext ClassLoader Current=com.bea.common.security.utils.SAML2ClassLoader@625ecb90>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.initialize LoginModuleClassName=weblogic.security.providers.authentication.LDAPAtnLoginModuleImpl>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.initialize ClassLoader=java.net.URLClassLoader@108c7fe5>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.initialize created delegate login module>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP ATN LoginModule initialized>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.initialize delegated>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.login>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP Atn Login>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle callbcacks[0] will be delegated>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle callbcacks[0] will use NameCallback to retrieve name>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle will delegate all callbacks>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Atn> <SAMLIACallbackHandler: callback[0]: NameCallback: setName(PATOU_MORGAN)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle delegated callbacks>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.CallbackHandlerWrapper.handle got username from callbacks[0], UserName=PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP Atn Login username: PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <getUserDNName? user:PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <getDNForUser search("ou=people,ou=internal,dc=company,dc=com", "(&(uid=PATOU_MORGAN)(objectclass=companyperson))", base DN & below)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <getConnection return conn:LDAPConnection {ldaps://ldap.company.com:3636 ldapVersion:3 bindDN:"ou=bind_user,ou=applications,ou=internal,dc=company,dc=com"}>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <ConnSetupMgr><Connecting to host=ldap.company.com, ssl port=3636>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <ConnSetupMgr><Successfully connected to host=ldap.company.com, ssl port=3636>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Retrieved guid:c6e6f021-2b29d761-8284c0aa-df200d0f>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <DN for user PATOU_MORGAN: uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <found user from ldap, user:PATOU_MORGAN, userDN=uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Retrieved username from LDAP :PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <returnConnection conn:LDAPConnection {ldaps://ldap.company.com:3636 ldapVersion:3 bindDN:"ou=bind_user,ou=applications,ou=internal,dc=company,dc=com"}>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP Atn Asserted Identity for PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <List groups that member: PATOU_MORGAN belongs to>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <DN for user PATOU_MORGAN: uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Retrieved dn:uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com for user:PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <search("ou=bind_user,ou=applications,ou=internal,dc=company,dc=com", "(&(uniquemember=uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com)(objectclass=groupofuniquenames))", base DN & below)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <getConnection return conn:LDAPConnection {ldaps://ldap.company.com:3636 ldapVersion:3 bindDN:"ou=bind_user,ou=applications,ou=internal,dc=company,dc=com"}>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Result has more elements: false>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <search("ou=bind_user,ou=applications,ou=internal,dc=company,dc=com", "(objectclass=groupofURLs)", base DN & below)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <returnConnection conn:LDAPConnection {ldaps://ldap.company.com:3636 ldapVersion:3 bindDN:"ou=bind_user,ou=applications,ou=internal,dc=company,dc=com"}>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <DN for user PATOU_MORGAN: uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Retrieved dn:uid=PATOU_MORGAN,ou=people,ou=internal,dc=company,dc=com for user:PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <login succeeded for username PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.login delegated, returning true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.commit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP Atn Commit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <LDAP Atn Principals Added>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.LoginModuleWrapper.commit delegated, returning true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login logged in>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login subject=Subject:
        Principal: PATOU_MORGAN
        Private Credential: PATOU_MORGAN
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <weblogic.security.service.internal.WLSIdentityServiceImpl.getIdentityFromSubject Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principals)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) Principal=PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) PrincipalClassName=weblogic.security.principal.WLSUserImpl>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) trying PrincipalValidator for interface weblogic.security.principal.WLSPrincipal>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) PrincipalValidator handles this PrincipalClass>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Generated signature and signed WLS principal PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) PrincipalValidator signed the principal>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.sign(Principal) All required PrincipalValidators signed this PrincipalClass, returning true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.JAASLoginServiceImpl.login identity=Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <weblogic.security.service.internal.WLSJAASLoginServiceImpl$ServiceImpl.authenticate authenticate succeeded for user PATOU_MORGAN, Identity=Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <weblogic.security.service.internal.WLSJAASLoginServiceImpl$ServiceImpl.authenticate login succeeded and PATOU_MORGAN was not previously locked out>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityCacheServiceImpl.cachedIdentity(Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
),cacheKe y= idm:_def_Idmusr:PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <Using redirect URL from request cache: 'https://d2.company.com:443/D2/X3_Portal.jsp'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <Redirecting to URL: https://d2.company.com:443/D2/X3_Portal.jsp>

 

At this point, the SAML2 exchange is successful and the user has been found in the LDAP successfully. So the only thing remaining is the validation of the user on WebLogic side as well as the access to the Application (D2 in this case). That’s where the logs of the WLS started to diverge.

On the WebLogic Server 1 (no issue), we can see WebLogic validating the user and finally granting access to the application:

<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityCacheServiceImpl.cachedIdentity(Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
),cacheKe y= idm:_def_Idmusr:PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <Using redirect URL from request cache: 'https://d2.company.com:443/D2/X3_Portal.jsp'>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecuritySAML2Service> <Redirecting to URL: https://d2.company.com:443/D2/X3_Portal.jsp>

<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <PrincipalAuthenticator.validateIdentity>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <PrincipalAuthenticator.validateIdentity will use common security service>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principals)>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) Principal=PATOU_MORGAN>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) PrincipalClassName=weblogic.security.principal.WLSUserImpl>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) trying PrincipalValidator for interface weblogic.security.principal.WLSPrincipal>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) PrincipalValidator handles this PrincipalClass>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <Validate WLS principal PATOU_MORGAN returns true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) PrincipalValidator said the principal is valid>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principal) One or more PrincipalValidators handled this PrincipalClass, returning true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.PrincipalValidationServiceImpl.validate(Principals) validated all principals>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <AuthorizationManager will use common security for ATZ>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <weblogic.security.service.WLSAuthorizationServiceWrapper.isAccessAllowed>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Identity=Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Roles=[ "Anonymous" "consumer" ]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Resource=type=<url>, application=D2, contextPath=/D2, uri=/X3_Portal.jsp, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Direction=ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): input arguments:>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> < Subject: 1
        Principal = weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> < Roles:Anonymous, consumer>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> < Resource: type=<url>, application=D2, contextPath=/D2, uri=/X3_Portal.jsp, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> < Direction: ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> < Context Handler: >
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Accessed Subject: Id=urn:oasis:names:tc:xacml:2.0:subject:role, Value=[Anonymous,consumer]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Evaluate urn:oasis:names:tc:xacml:1.0:function:string-at-least-one-member-of([consumer,consumer],[Anonymous,consumer]) -> true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <primary-rule evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <urn:bea:xacml:2.0:entitlement:resource:type@E@Furl@G@M@Oapplication@ED2@M@OcontextPath@E@UD2@M@Ouri@E@U@K@M@OhttpMethod@EGET, 1.0 evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): returning PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed AccessDecision returned PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AuthorizationServiceImpl.isAccessAllowed returning adjudicated: true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <AuthorizationManager will use common security for ATZ>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <weblogic.security.service.WLSAuthorizationServiceWrapper.isAccessAllowed>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Identity=Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Roles=[ "Anonymous" "consumer" ]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Resource=type=<url>, application=D2, contextPath=/D2, uri=/x3_portal/x3_portal.nocache.js, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Direction=ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): input arguments:>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Subject: 1
        Principal = weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Roles:Anonymous, consumer>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Resource: type=<url>, application=D2, contextPath=/D2, uri=/x3_portal/x3_portal.nocache.js, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Direction: ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Context Handler: >
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Accessed Subject: Id=urn:oasis:names:tc:xacml:2.0:subject:role, Value=[Anonymous,consumer]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Evaluate urn:oasis:names:tc:xacml:1.0:function:string-at-least-one-member-of([consumer,consumer],[Anonymous,consumer]) -> true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <primary-rule evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <urn:bea:xacml:2.0:entitlement:resource:type@E@Furl@G@M@Oapplication@ED2@M@OcontextPath@E@UD2@M@Ouri@E@U@K@M@OhttpMethod@EGET, 1.0 evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): returning PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed AccessDecision returned PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AuthorizationServiceImpl.isAccessAllowed returning adjudicated: true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <AuthorizationManager will use common security for ATZ>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <weblogic.security.service.WLSAuthorizationServiceWrapper.isAccessAllowed>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Identity=Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Roles=[ "Anonymous" "consumer" ]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Resource=type=<url>, application=D2, contextPath=/D2, uri=/x3_portal/79E87564DA9D026D7ADA9326E414D4FC.cache.js, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed Direction=ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): input arguments:>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Subject: 1
        Principal = weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Roles:Anonymous, consumer>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Resource: type=<url>, application=D2, contextPath=/D2, uri=/x3_portal/79E87564DA9D026D7ADA9326E414D4FC.cache.js, httpMethod=GET>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Direction: ONCE>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <        Context Handler: >
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Accessed Subject: Id=urn:oasis:names:tc:xacml:2.0:subject:role, Value=[Anonymous,consumer]>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <Evaluate urn:oasis:names:tc:xacml:1.0:function:string-at-least-one-member-of([consumer,consumer],[Anonymous,consumer]) -> true>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <primary-rule evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <urn:bea:xacml:2.0:entitlement:resource:type@E@Furl@G@M@Oapplication@ED2@M@OcontextPath@E@UD2@M@Ouri@E@U@K@M@OhttpMethod@EGET, 1.0 evaluates to Permit>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <XACML Authorization isAccessAllowed(): returning PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AccessDecisionServiceImpl.isAccessAllowed AccessDecision returned PERMIT>
<Nov 21, 2017 9:25:55 AM UTC> <Debug> <SecurityAtz> <com.bea.common.security.internal.service.AuthorizationServiceImpl.isAccessAllowed returning adjudicated: true>

 

On the other hand, the WebLogic Server 2 (with issue) didn’t even start to validate the user, it just started again the full SAML2 process:

<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecurityAtn> <com.bea.common.security.internal.service.IdentityCacheServiceImpl.cachedIdentity(Subject: 1
        Principal = class weblogic.security.principal.WLSUserImpl("PATOU_MORGAN")
),cacheKe y= idm:_def_Idmusr:PATOU_MORGAN>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <Using redirect URL from request cache: 'https://d2.company.com:443/D2/X3_Portal.jsp'>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <Redirecting to URL: https://d2.company.com:443/D2/X3_Portal.jsp>

<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <SAML2Filter: Processing request on URI '/D2/X3_Portal.jsp'>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is '/D2/X3_Portal.jsp'>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is not a service URI>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): returning service type 'SPinitiator'>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: processing>
<Nov 21, 2017 10:34:53 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: partner id is null>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <SP initiating authn request: use partner binding HTTP/POST>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <post from template url: null>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <SAML2Servlet: Processing request on URI '/saml2/sp/acs/post'>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): request URI is '/saml2/sp/acs/post'>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): service URI is '/sp/acs/post'>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <getServiceTypeFromURI(): returning service type 'ACS'>
<Nov 21, 2017 10:34:54 AM UTC> <Debug> <SecuritySAML2Service> <Assertion consumer service: processing>

 

This WebLogic Server 2 is acting just like if it was a completely new request and not an existing one… And this is the reaction I had when I saw this log so I checked the session identifier!

Whenever you configure an Application to support SAML2 SSO, then the session identifier must be the default one. If you set something else, then you will have this infinite loop of authentication because WebLogic will consider a successful authentication as a non-authenticated one. This is described in the Oracle documentation.

So to solve this issue, that’s pretty simple… Either comment the session identifier or set it to the default value (below I’m just resetting it to the default value):

[weblogic@weblogic_server_01 ~]$ cd $APPS_HOME
[weblogic@weblogic_server_01 apps]$ jar -xvf D2.war WEB-INF/weblogic.xml
 inflated: WEB-INF/weblogic.xml
[weblogic@weblogic_server_01 apps]$
[weblogic@weblogic_server_01 apps]$ sed -i 's,<cookie-name>[^<]*<,<cookie-name>JSESSIONID<,' WEB-INF/weblogic.xml
[weblogic@weblogic_server_01 apps]$
[weblogic@weblogic_server_01 apps]$ grep -A3 -B2 cookie-name WEB-INF/weblogic.xml

  <session-descriptor>
    <cookie-name>JSESSIONID</cookie-name>
    <cookie-http-only>false</cookie-http-only>
  </session-descriptor>

[weblogic@weblogic_server_01 apps]$
[weblogic@weblogic_server_01 apps]$ jar -uvf D2.war WEB-INF/weblogic.xml
adding: WEB-INF/weblogic.xml(in = 901) (out= 432)(deflated 52%)
[weblogic@weblogic_server_01 apps]$

 

Then you obviously need to redeploy your application and it will be working. :)

 

 

Leave a Reply


+ 6 = eight

Morgan Patou
Morgan Patou

Senior Consultant