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

Martin Choma (Jira) issues at jboss.org
Wed Oct 24 03:43:00 EDT 2018 

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

Martin Choma updated ELY-1703:
------------------------------
    Description: 
Test PrincipalMappingSuiteChild#testDnToDnVerify failed on read timeout (1:1000), 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}

  was:
Test PrincipalMappingSuiteChild#testDnToDnVerify failed on read timeout (1:1000), 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 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



> 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
>            Priority: Optional
>
> Test PrincipalMappingSuiteChild#testDnToDnVerify failed on read timeout (1:1000), 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