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)
