Uploaded image for project: 'PicketLink'
  1. PicketLink
  2. PLINK-731

Picketlink LDAP attribute mapping uses session ID instead of uid as filter after a cluster rolling restart

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Obsolete
    • Icon: Major Major
    • None
    • None
    • None
    • None
    • Hide

      Setup a cluster with LDAP attribute mapping module
      Establish sessions with lots of accounts
      Roll restart the cluster
      Try to continue to use all the users sessions
      Get white screen due to bad LDAP calls for some user sessions

      Show
      Setup a cluster with LDAP attribute mapping module Establish sessions with lots of accounts Roll restart the cluster Try to continue to use all the users sessions Get white screen due to bad LDAP calls for some user sessions

      We have two RHEL 6 nodes running JBoss EAP 6.4.0.GA (AS 7.5.0.Final-redhat-21)
      and jboss-as-picketlink-7.5.0-8.Final_redhat_21.1.ep6.el6.noarch in a cluster with session replication. They support GSSAPI auth and LDAP auth. They do attribute mapping via the LDAP attribute mapper.

      Recently we've noticed when taking one node out of rotation, then bringing it back in and taking the next node out and bringing it back in – while doing a release that people winding back up at the IDP end up at a white screen. PL serves a 200 to them and doesn't try to redirect or auth them any further. This happens very very rarely outside of a rolling cluster restart but immediately following the rolling cluster restart it happens hundreads of times for a day or more presumably until peoples IDP session cookies expire or until they close and re-open their browser or clear cache. It doesn't happen to all users so its somewhat hard to reproduce but from what I've gathered PL seems to be asking for LDAP attributes for what look like session data instead of the users UID.

      Here is what is in the JBOSS debug logs when the issue occurs. Full logs attached.

      2016-01-14 09:36:00,064 INFO [org.picketlink.common] (http-/10.5.103.113:8080-19) /idp RESPONSE_TO_SP https://NOPE.com/saml/sso [Info]
      2016-01-14 09:36:00,939 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-14) Header - null
      2016-01-14 09:36:00,939 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-14) No Authorization Header, initiating negotiation
      2016-01-14 09:36:02,587 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-12) Header - null
      2016-01-14 09:36:02,587 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-12) No Authorization Header, initiating negotiation
      2016-01-14 09:36:02,640 DEBUG [org.jboss.security] (http-/10.5.103.113:8080-21) PBOX000293: Exception caught: javax.naming.NamingException: PBOX000037: Search for context dc=redhat,dc=com found no results
      at org.jboss.security.mapping.providers.attribute.LdapAttributeMappingProvider.performMapping(LdapAttributeMappingProvider.java:217)
      at org.jboss.security.mapping.providers.attribute.LdapAttributeMappingProvider.performMapping(LdapAttributeMappingProvider.java:94)
      at org.jboss.security.mapping.MappingContext.performMapping(MappingContext.java:54)
      at org.picketlink.identity.federation.bindings.jboss.attribute.JBossAppServerAttributeManager.getAttributes(JBossAppServerAttributeManager.java:73)
      at org.picketlink.identity.federation.core.impl.DelegatedAttributeManager.getAttributes(DelegatedAttributeManager.java:67)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.processSAMLRequestMessage(AbstractIDPValve.java:834)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.handleSAMLMessage(AbstractIDPValve.java:457)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.invoke(AbstractIDPValve.java:404)
      at org.jboss.security.negotiation.NegotiationAuthenticator$WrapperValve.invoke(NegotiationAuthenticator.java:490)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:512)
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:559)
      at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
      at org.jboss.as.web.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:384)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
      at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_85]

      2016-01-14 09:36:02,643 ERROR [org.picketlink.common] (http-/10.5.103.113:8080-21) Exception in processing authentication:: org.picketlink.common.exceptions.ConfigurationException: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at org.picketlink.common.DefaultPicketLinkLogger.configurationError(DefaultPicketLinkLogger.java:726)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:101)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:118)
      at org.picketlink.identity.federation.api.saml.v2.response.SAML2Response.createResponseType(SAML2Response.java:236)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler$IDPAuthenticationHandler.getResponse(SAML2AuthenticationHandler.java:320)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler$IDPAuthenticationHandler.handleRequestType(SAML2AuthenticationHandler.java:241)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler.handleRequestType(SAML2AuthenticationHandler.java:128)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.processSAMLRequestMessage(AbstractIDPValve.java:861)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.handleSAMLMessage(AbstractIDPValve.java:457)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.invoke(AbstractIDPValve.java:404)
      at org.jboss.security.negotiation.NegotiationAuthenticator$WrapperValve.invoke(NegotiationAuthenticator.java:490)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:512)
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:559)
      at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
      at org.jboss.as.web.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:384)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
      at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_85]
      Caused by: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:135) [rt.jar:1.7.0_85]
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.newDatatypeFactory(XMLTimeUtil.java:244)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:99)
      ... 21 more
      Caused by: java.lang.ClassNotFoundException: _redirected/_DatatypeFactory
      at java.lang.Class.forName0(Native Method) [rt.jar:1.7.0_85]
      at java.lang.Class.forName(Class.java:278) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.getProviderClass(FactoryFinder.java:126) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:181) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:150) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.find(FactoryFinder.java:222) [rt.jar:1.7.0_85]
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:129) [rt.jar:1.7.0_85]
      ... 23 more
      2016-01-14 09:36:02,645 ERROR [org.picketlink.common] (http-/10.5.103.113:8080-21) Exception in processing request:: org.picketlink.common.exceptions.ProcessingException: PL00102: Processing Exception:
      at org.picketlink.common.DefaultPicketLinkLogger.processingError(DefaultPicketLinkLogger.java:174)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler$IDPAuthenticationHandler.handleRequestType(SAML2AuthenticationHandler.java:268)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler.handleRequestType(SAML2AuthenticationHandler.java:128)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.processSAMLRequestMessage(AbstractIDPValve.java:861)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.handleSAMLMessage(AbstractIDPValve.java:457)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.invoke(AbstractIDPValve.java:404)
      at org.jboss.security.negotiation.NegotiationAuthenticator$WrapperValve.invoke(NegotiationAuthenticator.java:490)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:512)
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:559)
      at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
      at org.jboss.as.web.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:384)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
      at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_85]
      Caused by: org.picketlink.common.exceptions.ConfigurationException: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at org.picketlink.common.DefaultPicketLinkLogger.configurationError(DefaultPicketLinkLogger.java:726)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:101)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:118)
      at org.picketlink.identity.federation.api.saml.v2.response.SAML2Response.createResponseType(SAML2Response.java:236)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler$IDPAuthenticationHandler.getResponse(SAML2AuthenticationHandler.java:320)
      at org.picketlink.identity.federation.web.handlers.saml2.SAML2AuthenticationHandler$IDPAuthenticationHandler.handleRequestType(SAML2AuthenticationHandler.java:241)
      ... 17 more
      Caused by: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:135) [rt.jar:1.7.0_85]
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.newDatatypeFactory(XMLTimeUtil.java:244)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:99)
      ... 21 more
      Caused by: java.lang.ClassNotFoundException: _redirected/_DatatypeFactory
      at java.lang.Class.forName0(Native Method) [rt.jar:1.7.0_85]
      at java.lang.Class.forName(Class.java:278) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.getProviderClass(FactoryFinder.java:126) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:181) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:150) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.find(FactoryFinder.java:222) [rt.jar:1.7.0_85]
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:129) [rt.jar:1.7.0_85]
      ... 23 more
      2016-01-14 09:36:02,648 ERROR [org.apache.catalina.connector] (http-/10.5.103.113:8080-21) JBWEB001018: An exception or error occurred in the container during the request processing: java.lang.RuntimeException: org.picketlink.common.exceptions.ConfigurationException: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at org.picketlink.identity.federation.api.saml.v2.response.SAML2Response.createResponseType(SAML2Response.java:307)
      at org.picketlink.identity.federation.web.util.IDPWebRequestUtil.getErrorResponse(IDPWebRequestUtil.java:304)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.processSAMLRequestMessage(AbstractIDPValve.java:884)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.handleSAMLMessage(AbstractIDPValve.java:457)
      at org.picketlink.identity.federation.bindings.tomcat.idp.AbstractIDPValve.invoke(AbstractIDPValve.java:404)
      at org.jboss.security.negotiation.NegotiationAuthenticator$WrapperValve.invoke(NegotiationAuthenticator.java:490)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:512)
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:559)
      at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
      at org.jboss.as.web.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:384)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
      at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_85]
      Caused by: org.picketlink.common.exceptions.ConfigurationException: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at org.picketlink.common.DefaultPicketLinkLogger.configurationError(DefaultPicketLinkLogger.java:726)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:101)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:118)
      at org.picketlink.identity.federation.api.saml.v2.response.SAML2Response.createResponseType(SAML2Response.java:305)
      ... 17 more
      Caused by: javax.xml.datatype.DatatypeConfigurationException: Provider _redirected._DatatypeFactory not found
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:135) [rt.jar:1.7.0_85]
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.newDatatypeFactory(XMLTimeUtil.java:244)
      at org.picketlink.identity.federation.core.saml.v2.util.XMLTimeUtil.getIssueInstant(XMLTimeUtil.java:99)
      ... 19 more
      Caused by: java.lang.ClassNotFoundException: _redirected/_DatatypeFactory
      at java.lang.Class.forName0(Native Method) [rt.jar:1.7.0_85]
      at java.lang.Class.forName(Class.java:278) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.getProviderClass(FactoryFinder.java:126) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:181) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.newInstance(FactoryFinder.java:150) [rt.jar:1.7.0_85]
      at javax.xml.datatype.FactoryFinder.find(FactoryFinder.java:222) [rt.jar:1.7.0_85]
      at javax.xml.datatype.DatatypeFactory.newInstance(DatatypeFactory.java:129) [rt.jar:1.7.0_85]
      ... 21 more

      2016-01-14 09:36:02,741 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-14) Header - null
      2016-01-14 09:36:02,741 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-14) No Authorization Header, initiating negotiation
      2016-01-14 09:36:04,425 DEBUG [org.picketlink.common] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) cancelToken::provider=org.picketlink.identity.federation.core.saml.v2.providers.SAML20AssertionTokenProvider@12b24323
      2016-01-14 09:36:04,467 DEBUG [org.picketlink.common] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) cancelToken::provider=org.picketlink.identity.federation.core.saml.v2.providers.SAML20AssertionTokenProvider@12b24323
      2016-01-14 09:36:05,969 DEBUG [org.jboss.security.negotiation.NegotiationAuthenticator] (http-/10.5.103.113:8080-3) Header - null

      Here is what a good LDAP query looks like in the RHDS logs when things are working.

      [08/Jan/2016:20:43:18 -0500] conn=494770 fd=67 slot=67 SSL connection from 10.5.103.113 to 10.5.110.51
      [08/Jan/2016:20:43:18 -0500] conn=494770 TLS1.0 256-bit AES
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=0 BIND dn="uid=picketlink,ou=serviceaccounts,dc=redhat,dc=com" method=128 version=3
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=picketlink,ou=serviceaccounts,dc=redhat,dc=com"
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=1 SRCH base="dc=redhat,dc=com" scope=2 filter="(uid=dminnich)" attrs="mail cn givenName sn rhatPersonType uid manager rhatCostCenterDesc rhatJobTitle rhatGeo"
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=1 RESULT err=0 tag=101 nentries=1 etime=0
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=2 SRCH base="uid=nhicher,ou=users,dc=redhat,dc=com" scope=2 filter="(uid=dminnich)" attrs="mail cn givenName sn rhatPersonType uid manager rhatCostCenterDesc rhatJobTitle rhatGeo"
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=2 RESULT err=0 tag=101 nentries=1 etime=0
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=3 UNBIND
      [08/Jan/2016:20:43:18 -0500] conn=494770 op=3 fd=67 closed - U1

      Here is what a bad LDAP query looks like in the RHDS logs when this issue is occuring.
      [13/Jan/2016:20:45:50 -0500] conn=571912 fd=70 slot=70 SSL connection from 10.5.103.112 to 10.5.110.51
      [13/Jan/2016:20:45:50 -0500] conn=571912 TLS1.0 256-bit AES
      [13/Jan/2016:20:45:50 -0500] conn=571912 op=0 BIND dn="uid=picketlink,ou=serviceaccounts,dc=redhat,dc=com" method=128 version=3
      [13/Jan/2016:20:45:50 -0500] conn=571912 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=picketlink,ou=serviceaccounts,dc=redhat,dc=com"
      [13/Jan/2016:20:45:50 -0500] conn=571912 op=1 SRCH base="dc=redhat,dc=com" scope=2 filter="(uid=NYWIhxrXaH3RmdflAt1lLSTE.s01_1452716486786)" attrs="mail cn givenName sn rhatPersonType uid manager rhatCostCenterDesc rhatJobTitle rhatGeo"
      [13/Jan/2016:20:45:50 -0500] conn=571912 op=1 RESULT err=0 tag=101 nentries=0 etime=0

            psilva@redhat.com Pedro Igor Craveiro
            rhit_dminnich Dustin Minnich
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: