Details
Blocker Description
Concurrent reads cause ApacheDS 2.0.0.M15 to periodically return the following incorrect responses.
[LDAP: error code 49 - INVALID_CREDENTIALS: Bind failed: null] - despite credentials being correct
[LDAP: error code 80 - OTHER: failed for MessageType : SEARCH_REQUEST - despite the entry being searched existing
[LDAP: error code 1 - OPERATIONS_ERROR: failed for MessageType : SEARCH_REQUEST - despite the entry being searched existing.
This can be reproduced using the default configuration distributed with ApacheDS 2.0.0.M15. I am unable to replicate the same behavior using ApacheDS 2.0.0.M14. My harness to produce the problem creates 5 LDAP search requests simultaneously for the same dn. All searches are exactly the same. However some of these searches fail at the BIND with the error 49 or at the search with error 1 or 80
When the requests fail I see the following ConcurrentModificationException written in the logs. For example in the case of BIND failure I see this.
[16:54:04] DEBUG [org.apache.directory.api.CODEC_LOG] - Encoded message
MessageType : BIND_RESPONSE
Message ID : 1
BindResponse
Ldap Result
Result code : (INVALID_CREDENTIALS) invalidCredentials
Matched Dn : 'null'
Diagnostic message : 'INVALID_CREDENTIALS: Bind failed: null:
java.util.ConcurrentModificationException
at java.util.HashMap$HashIterator.nextEntry(HashMap.java:894)
at java.util.HashMap$ValueIterator.next(HashMap.java:922)
at java.util.Collections$UnmodifiableCollection$1.next(Collections.java:1067)
at org.apache.directory.server.core.api.entry.ServerEntryUtils.filterContents(ServerEntryUtils.java:771)
at org.apache.directory.server.core.schema.SchemaInterceptor.lookup(SchemaInterceptor.java:1130)
at org.apache.directory.server.core.api.interceptor.BaseInterceptor.next(BaseInterceptor.java:558)
at org.apache.directory.server.core.authz.DefaultAuthorizationInterceptor.lookup(DefaultAuthorizationInterceptor.java:235)
at org.apache.directory.server.core.api.interceptor.BaseInterceptor.next(BaseInterceptor.java:558)
at org.apache.directory.server.core.authz.AciAuthorizationInterceptor.lookup(AciAuthorizationInterceptor.java:777)
at org.apache.directory.server.core.api.interceptor.BaseInterceptor.next(BaseInterceptor.java:558)
at org.apache.directory.server.core.authn.AuthenticationInterceptor.lookup(AuthenticationInterceptor.java:802)
at org.apache.directory.server.core.api.interceptor.BaseInterceptor.next(BaseInterceptor.java:558)
at org.apache.directory.server.core.normalization.NormalizationInterceptor.lookup(NormalizationInterceptor.java:192)
at org.apache.directory.server.core.DefaultOperationManager.lookup(DefaultOperationManager.java:772)
at org.apache.directory.server.core.shared.DefaultCoreSession.lookup(DefaultCoreSession.java:542)
at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handleSimpleAuth(BindRequestHandler.java:147)
at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handle(BindRequestHandler.java:626)
at org.apache.directory.server.ldap.handlers.request.BindRequestHandler.handle(BindRequestHandler.java:66)
at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:193)
at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:56)
at org.apache.mina.handler.demux.DemuxingIoHandler.messageReceived(DemuxingIoHandler.java:221)
at org.apache.directory.server.ldap.LdapProtocolHandler.messageReceived(LdapProtocolHandler.java:217)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:690)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:417)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:47)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:765)
at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:74)
at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.runTask(UnorderedThreadPoolExecutor.java:474)
at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.run(UnorderedThreadPoolExecutor.java:428)
at java.lang.Thread.run(Thread.java:722)
And for the Search failure I see this.
[16:56:19] DEBUG [org.apache.directory.api.CODEC_LOG] - Encoded message
MessageType : SEARCH_RESULT_DONE
Message ID : 5
Search Result Done
Ldap Result
Result code : (OTHER) other
Matched Dn : 'null'
Diagnostic message : 'OTHER: failed for MessageType : SEARCH_REQUEST
Message ID : 5
SearchRequest
baseDn : 'uid=pbayliss,ou=users,dc=example,dc=com'
filter : '(objectClass=*)'
scope : base object
typesOnly : false
Size Limit : no limit
Time Limit : no limit
Deref Aliases : deref Always
attributes :
org.apache.directory.api.ldap.model.message.SearchRequestImpl@83c6a562 ManageDsaITImpl Control
Type OID : '2.16.840.1.113730.3.4.2'
Criticality : 'false'
'
: null:
java.util.ConcurrentModificationException
at java.util.HashMap$HashIterator.nextEntry(HashMap.java:894)
at java.util.HashMap$ValueIterator.next(HashMap.java:922)
at java.util.Collections$UnmodifiableCollection$1.next(Collections.java:1067)
at org.apache.directory.server.core.api.entry.ServerEntryUtils.filterContents(ServerEntryUtils.java:771)
at org.apache.directory.server.core.schema.SchemaInterceptor$TopFilter.accept(SchemaInterceptor.java:883)
at org.apache.directory.server.core.api.filtering.BaseEntryFilteringCursor.next(BaseEntryFilteringCursor.java:427)
at org.apache.directory.server.ldap.handlers.request.SearchRequestHandler.writeResults(SearchRequestHandler.java:391)
at org.apache.directory.server.ldap.handlers.request.SearchRequestHandler.doSimpleSearch(SearchRequestHandler.java:845)
at org.apache.directory.server.ldap.handlers.request.SearchRequestHandler.handleIgnoringReferrals(SearchRequestHandler.java:1153)
at org.apache.directory.server.ldap.handlers.request.SearchRequestHandler.handle(SearchRequestHandler.java:206)
at org.apache.directory.server.ldap.handlers.request.SearchRequestHandler.handle(SearchRequestHandler.java:92)
at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:207)
at org.apache.directory.server.ldap.handlers.LdapRequestHandler.handleMessage(LdapRequestHandler.java:56)
at org.apache.mina.handler.demux.DemuxingIoHandler.messageReceived(DemuxingIoHandler.java:221)
at org.apache.directory.server.ldap.LdapProtocolHandler.messageReceived(LdapProtocolHandler.java:217)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:690)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:417)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:47)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:765)
at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:74)
at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.runTask(UnorderedThreadPoolExecutor.java:474)
at org.apache.mina.filter.executor.UnorderedThreadPoolExecutor$Worker.run(UnorderedThreadPoolExecutor.java:428)
at java.lang.Thread.run(Thread.java:722)
Please let me know what you need to work this issue. I can provide the harness that I used, Wireshark traces, instance data from the directories and anything else you need such as logs.
Many thanks,
Paul