Uploaded image for project: 'WildFly Elytron'
  1. WildFly Elytron
  2. ELY-1703

Intermittent failure of PrincipalMappingSuiteChild#testDnToDnVerify

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Optional
    • Resolution: Done
    • Affects Version/s: 1.7.0.CR3
    • Fix Version/s: 1.8.0.Final
    • Component/s: Testsuite
    • Labels:
      None

      Description

      Test PrincipalMappingSuiteChild#testDnToDnVerify failed (1:1000) on read timeout, which is 60 s. So probably prolonging timeout is not an option. Maybe solution is implement some kind of retry?

      Error Message

      ELY01108: Ldap-backed realm identity search failed

      Stacktrace

      org.wildfly.security.auth.server.RealmUnavailableException: ELY01108: Ldap-backed realm identity search failed
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapSearch.search(LdapSecurityRealm.java:1141)
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapRealmIdentity.getIdentity(LdapSecurityRealm.java:688)
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapRealmIdentity.getIdentity(LdapSecurityRealm.java:669)
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapRealmIdentity.exists(LdapSecurityRealm.java:624)
      	at org.wildfly.security.ldap.PrincipalMappingSuiteChild.testDnToDnVerify(PrincipalMappingSuiteChild.java:132)
      	at org.wildfly.security.ldap.DirContextFactoryRule$1.evaluate(DirContextFactoryRule.java:218)
      Caused by: javax.naming.NamingException: LDAP response read timed out, timeout used:60000ms.; remaining name 'uid=nobody,dc=elytron,dc=wildfly,dc=org'
      	at java.naming/com.sun.jndi.ldap.Connection.readReply(Connection.java:443)
      	at java.naming/com.sun.jndi.ldap.LdapClient.processReply(LdapClient.java:888)
      	at java.naming/com.sun.jndi.ldap.LdapClient.compare(LdapClient.java:1168)
      	at java.naming/com.sun.jndi.ldap.LdapCtx.compare(LdapCtx.java:2117)
      	at java.naming/com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1840)
      	at java.naming/com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1770)
      	at java.naming/com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1787)
      	at java.naming/com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:418)
      	at java.naming/com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:396)
      	at java.naming/javax.naming.directory.InitialDirContext.search(InitialDirContext.java:297)
      	at org.wildfly.security.auth.realm.ldap.DelegatingLdapContext.search(DelegatingLdapContext.java:336)
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapSearch.searchWithPagination(LdapSecurityRealm.java:1161)
      	at org.wildfly.security.auth.realm.ldap.LdapSecurityRealm$LdapSearch.search(LdapSecurityRealm.java:1038)
      	... 5 more
      
      21:11:54,245 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:695> Identity for principal [uid=nobody,dc=elytron,dc=wildfly,dc=org] not found.
      21:11:54,245 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:628> Principal [uid=nobody,dc=elytron,dc=wildfly,dc=org] does not exists.
      21:11:54,248 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:463> Context [javax.naming.ldap.InitialLdapContext@2dba05b1] was closed. Connection closed or just returned to the pool.
      21:11:54,249 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:189> Obtaining lock for identity [uid=PlainUser,dc=elytron,dc=wildfly,dc=org]...
      21:11:54,249 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:197> Obtained lock for identity [uid=PlainUser,dc=elytron,dc=wildfly,dc=org].
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:427> Creating [class javax.naming.directory.InitialDirContext] with environment:
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.credentials] with value [******]
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.ldap.factory.socket] with value [org.wildfly.security.auth.realm.ldap.ThreadLocalSSLSocketFactory]
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.authentication] with value [simple]
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.provider.url] with value [ldap://localhost:11390/]
      21:11:54,249 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [com.sun.jndi.ldap.read.timeout] with value [60000]
      21:11:54,250 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [com.sun.jndi.ldap.connect.timeout] with value [5000]
      21:11:54,250 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.principal] with value [uid=server,dc=elytron,dc=wildfly,dc=org]
      21:11:54,250 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.referral] with value [ignore]
      21:11:54,250 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.factory.initial] with value [com.sun.jndi.ldap.LdapCtxFactory]
      21:11:54,300 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:444> [javax.naming.ldap.InitialLdapContext@31b0f02] successfully created. Connection established to LDAP server.
      21:11:54,300 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:673> Trying to create identity for principal [uid=PlainUser,dc=elytron,dc=wildfly,dc=org].
      21:11:54,300 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:1027> Executing search [(uid={0})] in context [uid=PlainUser,dc=elytron,dc=wildfly,dc=org] with arguments [PlainUser]. Returning attributes are [null]. Binary attributes are [null].
      21:11:54,302 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:1096> Found entry [uid=PlainUser,dc=elytron,dc=wildfly,dc=org].
      21:11:54,302 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:692> Identity for principal [uid=PlainUser,dc=elytron,dc=wildfly,dc=org] found at [uid=PlainUser,dc=elytron,dc=wildfly,dc=org].
      21:11:54,303 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:463> Context [javax.naming.ldap.InitialLdapContext@31b0f02] was closed. Connection closed or just returned to the pool.
      21:11:54,303 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:189> Obtaining lock for identity [uid=nobody,dc=elytron,dc=wildfly,dc=org]...
      21:11:54,303 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:197> Obtained lock for identity [uid=nobody,dc=elytron,dc=wildfly,dc=org].
      21:11:54,303 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:427> Creating [class javax.naming.directory.InitialDirContext] with environment:
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.credentials] with value [******]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.ldap.factory.socket] with value [org.wildfly.security.auth.realm.ldap.ThreadLocalSSLSocketFactory]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.authentication] with value [simple]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.provider.url] with value [ldap://localhost:11390/]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [com.sun.jndi.ldap.read.timeout] with value [60000]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [com.sun.jndi.ldap.connect.timeout] with value [5000]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.security.principal] with value [uid=server,dc=elytron,dc=wildfly,dc=org]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.referral] with value [ignore]
      21:11:54,304 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:428>     Property [java.naming.factory.initial] with value [com.sun.jndi.ldap.LdapCtxFactory]
      21:11:54,354 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:444> [javax.naming.ldap.InitialLdapContext@19ae2ee5] successfully created. Connection established to LDAP server.
      21:11:54,354 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:673> Trying to create identity for principal [uid=nobody,dc=elytron,dc=wildfly,dc=org].
      21:11:54,354 DEBUG (main) [org.wildfly.security] <LdapSecurityRealm.java:1027> Executing search [(uid={0})] in context [uid=nobody,dc=elytron,dc=wildfly,dc=org] with arguments [nobody]. Returning attributes are [null]. Binary attributes are [null].
      21:12:54,358 WARN  (pool-3-thread-2) [org.apache.directory.server.ldap.LdapSession] <LdapSession.java:254> AbandonableRequest with messageId 2 not found in outstandingRequests.
      21:12:54,364 DEBUG (main) [org.wildfly.security] <SimpleDirContextFactoryBuilder.java:463> Context [javax.naming.ldap.InitialLdapContext@19ae2ee5] was closed. Connection closed or just returned to the pool.
      21:12:54,368 INFO  (pool-3-thread-2) [org.apache.directory.server.ldap.handlers.LdapRequestHandler] <LdapRequestHandler.java:131> ignoring the message MessageType : UNBIND_REQUEST
      Message ID : 4
          UnBind Requestorg.apache.directory.api.ldap.model.message.UnbindRequestImpl@949b7f8    ManageDsaITImpl Control
              Type OID    : '2.16.840.1.113730.3.4.2'
              Criticality : 'false'
      '
       received from null session
      

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                jucook Justin Cook
                Reporter:
                mchoma Martin Choma
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: