[jira] [Created] (DIRSERVER-2193) Corruption of JDBM partition during concurrent InvalidCredentials when password policy enabled

["Ben Hawkins (JIRA)" <ji...@apache.org>]

Ben Hawkins created DIRSERVER-2193:
--------------------------------------

             Summary: Corruption of JDBM partition during concurrent InvalidCredentials when password policy enabled
                 Key: DIRSERVER-2193
                 URL: https://issues.apache.org/jira/browse/DIRSERVER-2193
             Project: Directory ApacheDS
          Issue Type: Bug
    Affects Versions: 2.0.0-M23, 2.0.0-M20
         Environment: Running on Oracle Linux 6.8 with JRE 1.8.0_60. JDBM partition type, sync-on-write enabled.
            Reporter: Ben Hawkins


I have encountered several cases in which apacheDS 2.0.0-MS20 and subsequently MS23 have been corrupted. When this happens, I see messages like the following when shutting down apacheDS: invalid stream header: 7A69707A. After the issue occurs, some search operations return this "invalid stream header message" along an "OTHER" response code. Usually, after restart, the server cannot be started again, and must be wiped and restored from an LDIF backup.

After a few events, one common thread that appeared was that each corruption event was preceded by a spike in InvalidCredentials requests (BIND as existing user, but with bad password). Eventually, I narrowed it down to coincide with a message in the log like:

{noformat}
[04:05:40] WARN [org.apache.directory.api.ldap.model.entry.DefaultAttribute] - ERR_04486_VALUE_ALREADY_EXISTS The value '20170428040540.892Z' already exists in the attribute (pwdFailureTime)
[04:05:40] WARN [org.apache.directory.api.ldap.model.entry.DefaultAttribute] - ERR_04486_VALUE_ALREADY_EXISTS The value '20170428040540.892Z' already exists in the attribute (pwdFailureTime)
[04:05:40] WARN [org.apache.directory.api.ldap.model.entry.DefaultAttribute] - ERR_04486_VALUE_ALREADY_EXISTS The value '20170428040540.892Z' already exists in the attribute (pwdFailureTime)
{noformat}

I was able to recreate the issue with a jmeter test by sending bad credentials with multiple threads. My (JDBM) partition has about 2,000 records in it. I'm not sure if it's a function of size, or if the same would happen with a fresh back-end containing only a few records.

Disabling the password policy on the server seems to prevent this from happening, as the pwdFailureTime is no longer updated on the back-end database.

Full stack trace on failing server shutdown:

{noformat}
 [12:32:06] ERROR [org.apache.directory.server.core.authz.GroupCache] - Exception while initializing the groupCache:¿¿{}
org.apache.directory.api.ldap.model.exception.LdapOperationErrorException: invalid stream header: 7A69707A
¿¿at org.apache.directory.server.core.partition.impl.btree.AbstractBTreePartition.fetch(AbstractBTreePartition.java:1227)
¿¿at org.apache.directory.server.xdbm.search.evaluator.EqualityEvaluator.evaluate(EqualityEvaluator.java:97)
¿¿at org.apache.directory.server.xdbm.search.evaluator.OrEvaluator.evaluate(OrEvaluator.java:85)
¿¿at org.apache.directory.server.xdbm.search.evaluator.AndEvaluator.evaluate(AndEvaluator.java:110)
¿¿at org.apache.directory.server.core.partition.impl.btree.EntryCursorAdaptor.get(EntryCursorAdaptor.java:169)
¿¿at org.apache.directory.server.core.partition.impl.btree.EntryCursorAdaptor.get(EntryCursorAdaptor.java:45)
¿¿at org.apache.directory.server.core.api.filtering.EntryFilteringCursorImpl.next(EntryFilteringCursorImpl.java:405)
¿¿at org.apache.directory.server.core.authz.GroupCache.initialize(GroupCache.java:157)
¿¿at org.apache.directory.server.core.authz.GroupCache.<init>(GroupCache.java:115)
¿¿at org.apache.directory.server.core.authz.AciAuthorizationInterceptor.init(AciAuthorizationInterceptor.java:288)
¿¿at org.apache.directory.server.core.DefaultDirectoryService.initInterceptors(DefaultDirectoryService.java:692)
¿¿at org.apache.directory.server.core.DefaultDirectoryService.initialize(DefaultDirectoryService.java:1829)
¿¿at org.apache.directory.server.core.DefaultDirectoryService.startup(DefaultDirectoryService.java:1251)
¿¿at org.apache.directory.server.ApacheDsService.initDirectoryService(ApacheDsService.java:367)
¿¿at org.apache.directory.server.ApacheDsService.start(ApacheDsService.java:183)
¿¿at org.apache.directory.server.wrapper.ApacheDsTanukiWrapper.repair(ApacheDsTanukiWrapper.java:102)
¿¿at org.apache.directory.server.wrapper.ApacheDsTanukiWrapper.start(ApacheDsTanukiWrapper.java:193)
¿¿at org.tanukisoftware.wrapper.WrapperManager$12.run(WrapperManager.java:2788)
{noformat}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)