[jboss-jira] [JBoss JIRA] (ELY-1703) Intermittent failure of PrincipalMappingSuiteChild#testDnToDnVerify

Farah Juma (Jira) issues at jboss.org
Wed Feb 20 10:36:00 EST 2019


     [ https://issues.jboss.org/browse/ELY-1703?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Farah Juma resolved ELY-1703.
-----------------------------
    Resolution: Done


> Intermittent failure of PrincipalMappingSuiteChild#testDnToDnVerify
> -------------------------------------------------------------------
>
>                 Key: ELY-1703
>                 URL: https://issues.jboss.org/browse/ELY-1703
>             Project: WildFly Elytron
>          Issue Type: Bug
>          Components: Testsuite
>    Affects Versions: 1.7.0.CR3
>            Reporter: Martin Choma
>            Assignee: Justin Cook
>            Priority: Optional
>             Fix For: 1.8.0.CR3
>
>
> 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
> {noformat}
> 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
> {noformat}
> {noformat}
> 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 at 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 at 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 at 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 at 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 at 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 at 949b7f8    ManageDsaITImpl Control
>         Type OID    : '2.16.840.1.113730.3.4.2'
>         Criticality : 'false'
> '
>  received from null session
> {noformat}



--
This message was sent by Atlassian Jira
(v7.12.1#712002)


More information about the jboss-jira mailing list