Uploaded image for project: 'OpenDJ'
  1. OpenDJ
  2. OPENDJ-1692

Collection of potential performance improvements for use as CTS store

    Details

      Description

      OpenAM's usage of DJ as a CTS is exposing some potential new performance contention points. Typical CTS load is made up of a high proportion of add/delete operations (adding and expiring sessions, tokens, etc). Whilst DJ has been optimized for a high proportion of modify load, it has not been optimized for adds and deletes, hence we are seeing some new bottlenecks.

      This epic captures test observations and will spawn of various performance RFEs.

      The data model:

      • tokens are stored under a single parent entry
      • tokens are indexed on the expiration timestamp (coreTokenExpirationDate) which is a generalized time attribute
      • expired tokens are purged by an application thread in OpenAM which performs an ordering match search against coreTokenExpirationDate to find the candidates.

      Performance observations:

      1. 25% of the stack traces showed no activity in OpenDJ - possible bad test or contention in AM?
      2. contention on id2children and id2subtree: this is expected since all entries are being added/deleted beneath the same parent, so all transactions hit the same id2x records. Resolved by disabling the subtree indexes using the subordinate-indexes-enabled option in the backend
      3. with subordinate indexes disabled over 60% of stack traces showed that OpenDJ was mostly idle
      4. contention on dn2id index:
        1. check in local backend workflow element to determine if the entry to be added has a parent
        2. repeat check in JE backend (redundant?)
        3. iteration up the ancestor hierarchy in order to determine which id2children/subtree records to update, despite these indexes being disabled!
          	at org.opends.server.backends.jeb.DatabaseContainer.read(DatabaseContainer.java:201)
          	at org.opends.server.backends.jeb.DN2ID.read(DN2ID.java:245)
          	at org.opends.server.backends.jeb.DN2ID.get(DN2ID.java:229)
          	at org.opends.server.backends.jeb.EntryContainer.getEntry(EntryContainer.java:2214)
          	at org.opends.server.backends.jeb.BackendImpl.getEntry(BackendImpl.java:731)
          	at org.opends.server.core.DirectoryServer.getEntry(DirectoryServer.java:6688)
          	at org.opends.server.workflowelement.localbackend.LocalBackendAddOperation.processLocalAdd(LocalBackendAddOperation.java:354)
          	at org.opends.server.workflowelement.localbackend.LocalBackendWorkflowElement.execute(LocalBackendWorkflowElement.java:550)
          
          	at com.sleepycat.je.Database.get(Database.java:1294)
          	at org.opends.server.backends.jeb.DatabaseContainer.read(DatabaseContainer.java:201)
          	at org.opends.server.backends.jeb.DN2ID.read(DN2ID.java:245)
          	at org.opends.server.backends.jeb.DN2ID.get(DN2ID.java:229)
          	at org.opends.server.backends.jeb.EntryContainer.addEntry(EntryContainer.java:1735)
          	at org.opends.server.backends.jeb.BackendImpl.addEntry(BackendImpl.java:778)
          	at org.opends.server.workflowelement.localbackend.LocalBackendAddOperation.processLocalAdd(LocalBackendAddOperation.java:607)
          
          	at com.sleepycat.je.Database.get(Database.java:1294)
          	at org.opends.server.backends.jeb.DatabaseContainer.read(DatabaseContainer.java:201)
          	at org.opends.server.backends.jeb.DN2ID.read(DN2ID.java:245)
          	at org.opends.server.backends.jeb.DN2ID.get(DN2ID.java:229)
          	at org.opends.server.backends.jeb.EntryContainer.getEntry(EntryContainer.java:2214)
          	at org.opends.server.backends.jeb.BackendImpl.getEntry(BackendImpl.java:731)
          	at org.opends.server.core.DirectoryServer.getEntry(DirectoryServer.java:6688)
          
      5. occasional contention on SubentryManager when purging:
        "Worker Thread 17" prio=10 tid=0x00007f277ce6c800 nid=0x4c66 runnable [0x00007f276a7e6000]
           java.lang.Thread.State: WAITING (parking)
        	at sun.misc.Unsafe.park(Native Method)
        	- parking to wait for  <0x00000007420ab550> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
        	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
        	at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
        	at org.opends.server.core.SubentryManager.getSubentries(SubentryManager.java:519)
        	at org.opends.server.api.AuthenticationPolicy.forUser(AuthenticationPolicy.java:170)
        	at org.opends.server.workflowelement.localbackend.LocalBackendAddOperation.handlePasswordPolicy(LocalBackendAddOperation.java:957)
        	at org.opends.server.workflowelement.localbackend.LocalBackendAddOperation.processLocalAdd(LocalBackendAddOperation.java:452)
        	at org.opends.server.workflowelement.localbackend.LocalBackendWorkflowElement.execute(LocalBackendWorkflowElement.java:550)
        	at org.opends.server.core.WorkflowImpl.execute(WorkflowImpl.java:197)
        	at org.opends.server.core.WorkflowTopologyNode.execute(WorkflowTopologyNode.java:100)
        	at org.opends.server.core.AddOperationBasis.run(AddOperationBasis.java:764)
        	at org.opends.server.extensions.TraditionalWorkerThread.run(TraditionalWorkerThread.java:167)
        
        "Worker Thread 1" prio=10 tid=0x00007f277ce24000 nid=0x4c56 runnable [0x00007f276b7f6000]
           java.lang.Thread.State: RUNNABLE
        	at sun.misc.Unsafe.unpark(Native Method)
        	at java.util.concurrent.locks.LockSupport.unpark(LockSupport.java:152)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.unparkSuccessor(AbstractQueuedSynchronizer.java:662)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doReleaseShared(AbstractQueuedSynchronizer.java:689)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.setHeadAndPropagate(AbstractQueuedSynchronizer.java:729)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:956)
        	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
        	at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
        	at org.opends.server.core.SubentryManager.doPreOperation(SubentryManager.java:981)
        	at org.opends.server.core.PluginConfigManager.invokePreOperationDeletePlugins(PluginConfigManager.java:2922)
        	at org.opends.server.workflowelement.localbackend.LocalBackendDeleteOperation.processLocalDelete(LocalBackendDeleteOperation.java:279)
        	at org.opends.server.workflowelement.localbackend.LocalBackendWorkflowElement.execute(LocalBackendWorkflowElement.java:556)
        	at org.opends.server.core.WorkflowImpl.execute(WorkflowImpl.java:197)
        	at org.opends.server.core.WorkflowTopologyNode.execute(WorkflowTopologyNode.java:100)
        	at org.opends.server.core.DeleteOperationBasis.run(DeleteOperationBasis.java:417)
        	at org.opends.server.extensions.TraditionalWorkerThread.run(TraditionalWorkerThread.java:167)
        
      6. potential contention indexing the generalized time expiration attribute (coreTokenExpirationDate). In addition, unnecessary decoding of normalized generalized time values (fixed in DJ3). The following stacks are unrelated but show one thread blocked and one indexing timestamps:
        "Worker Thread 3" prio=10 tid=0x00007f277ce4f800 nid=0x4c58 runnable [0x00007f276b5f3000]
           java.lang.Thread.State: RUNNABLE
        	at java.lang.StringCoding$StringDecoder.decode(StringCoding.java:153)
        	at java.lang.StringCoding.decode(StringCoding.java:193)
        	at java.lang.String.<init>(String.java:416)
        	at org.opends.server.types.ByteString.toString(ByteString.java:343)
        	at org.opends.server.types.ByteString.toString(ByteString.java:793)
        	at org.opends.server.schema.GeneralizedTimeSyntax.decodeGeneralizedTimeValue(GeneralizedTimeSyntax.java:429)
        	at org.opends.server.schema.GeneralizedTimeOrderingMatchingRule.compareValues(GeneralizedTimeOrderingMatchingRule.java:212)
        	at org.opends.server.schema.GeneralizedTimeOrderingMatchingRule.compare(GeneralizedTimeOrderingMatchingRule.java:256)
        	at org.opends.server.schema.GeneralizedTimeOrderingMatchingRule.compare(GeneralizedTimeOrderingMatchingRule.java:53)
        	at com.sleepycat.je.tree.Key.compareKeys(Key.java:188)
        	at com.sleepycat.je.tree.IN.findEntry(IN.java:2267)
        	at com.sleepycat.je.tree.Tree.searchSubTreeUntilSplit(Tree.java:1805)
        	at com.sleepycat.je.tree.Tree.searchSubTreeSplitsAllowed(Tree.java:1755)
        	at com.sleepycat.je.tree.Tree.searchSplitsAllowed(Tree.java:1318)
        	at com.sleepycat.je.tree.Tree.findBinForInsert(Tree.java:2238)
        	at com.sleepycat.je.dbi.CursorImpl.putInternal(CursorImpl.java:875)
        	at com.sleepycat.je.dbi.CursorImpl.put(CursorImpl.java:816)
        	at com.sleepycat.je.Cursor.putAllowPhantoms(Cursor.java:2397)
        	at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:2352)
        	at com.sleepycat.je.Cursor.putNotify(Cursor.java:2260)
        	at com.sleepycat.je.Cursor.putNoDups(Cursor.java:2149)
        	at com.sleepycat.je.Cursor.putInternal(Cursor.java:2117)
        	- locked <0x00000007f12bb280> (a com.sleepycat.je.Transaction)
        	at com.sleepycat.je.Database.putInternal(Database.java:1580)
        	at com.sleepycat.je.Database.putNoOverwrite(Database.java:1500)
        	at org.opends.server.backends.jeb.DatabaseContainer.insert(DatabaseContainer.java:223)
        	at org.opends.server.backends.jeb.Index.insertID(Index.java:290)
        	at org.opends.server.backends.jeb.Index.addEntry(Index.java:1255)
        	at org.opends.server.backends.jeb.AttributeIndex.addEntry(AttributeIndex.java:545)
        	at org.opends.server.backends.jeb.EntryContainer.indexInsertEntry(EntryContainer.java:2988)
        	at org.opends.server.backends.jeb.EntryContainer.addEntry(EntryContainer.java:1716)
        	at org.opends.server.backends.jeb.BackendImpl.addEntry(BackendImpl.java:778)
        
        "Worker Thread 13" prio=10 tid=0x00007f277ce64000 nid=0x4c62 in Object.wait() [0x00007f276abe9000]
           java.lang.Thread.State: WAITING (on object monitor)
        	at java.lang.Object.wait(Native Method)
        	at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:351)
        	at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
        	- locked <0x00000007d5ea1d00> (a com.sleepycat.je.txn.ReadCommittedLocker)
        	at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:118)
        	at com.sleepycat.je.txn.ReadCommittedLocker.lockInternal(ReadCommittedLocker.java:84)
        	at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
        	at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2636)
        	at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2437)
        	at com.sleepycat.je.dbi.CursorImpl.searchAndPosition(CursorImpl.java:2163)
        	at com.sleepycat.je.Cursor.searchInternal(Cursor.java:2822)
        	at com.sleepycat.je.Cursor.searchAllowPhantoms(Cursor.java:2732)
        	at com.sleepycat.je.Cursor.searchNoDups(Cursor.java:2586)
        	at com.sleepycat.je.Cursor.search(Cursor.java:2553)
        	- locked <0x00000007d5e9c010> (a com.sleepycat.je.Transaction)
        	at com.sleepycat.je.Database.get(Database.java:1294)
        	at org.opends.server.backends.jeb.DatabaseContainer.read(DatabaseContainer.java:201)
        	at org.opends.server.backends.jeb.Index.insertID(Index.java:268)
        	at org.opends.server.backends.jeb.Index.addEntry(Index.java:1255)
        	at org.opends.server.backends.jeb.AttributeIndex.addEntry(AttributeIndex.java:521)
        	at org.opends.server.backends.jeb.EntryContainer.indexInsertEntry(EntryContainer.java:2988)
        	at org.opends.server.backends.jeb.EntryContainer.addEntry(EntryContainer.java:1716)
        	at org.opends.server.backends.jeb.BackendImpl.addEntry(BackendImpl.java:778)
        	at org.opends.server.workflowelement.localbackend.LocalBackendAddOperation.processLocalAdd(LocalBackendAddOperation.java:607)
        	at org.opends.server.workflowelement.localbackend.LocalBackendWorkflowElement.execute(LocalBackendWorkflowElement.java:550)
        	at org.opends.server.core.WorkflowImpl.execute(WorkflowImpl.java:197)
        	at org.opends.server.core.WorkflowTopologyNode.execute(WorkflowTopologyNode.java:100)
        	at org.opends.server.core.AddOperationBasis.run(AddOperationBasis.java:764)
        	at org.opends.server.extensions.TraditionalWorkerThread.run(TraditionalWorkerThread.java:167)
        

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                matthew Matthew Swift
                Reporter:
                rwapshott Robert Wapshott
                Dev Assignee:
                Matthew Swift
              • Votes:
                1 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: