andykimpe / rpms / 389-ds-base

Forked from rpms/389-ds-base 5 months ago
Clone
c04070
From 17aada4feb87407e004a890225700e730778d692 Mon Sep 17 00:00:00 2001
c04070
From: Mark Reynolds <mreynolds@redhat.com>
c04070
Date: Thu, 20 Jun 2019 15:50:08 -0400
c04070
Subject: [PATCH 1/2] BZ1518320 - entry cache crash fix
c04070
c04070
Description: THis patch is combination of all the entry cache fixes.
c04070
c04070
             If these fixes are not enough, there is an experimental
c04070
             "fix" that should prevent the crash.  A message will be
c04070
             logged that reports the crash was averted:
c04070
c04070
                  "(avoided crash, but cache was corrupted)"
c04070
c04070
             The customer should monitor the errors log for this text,
c04070
             and let GSS know if they see it.
c04070
---
c04070
 configure.ac                                  |   3 -
c04070
 dirsrvtests/tests/suites/betxns/betxn_test.py |  57 ++++++
c04070
 ldap/servers/slapd/back-ldbm/back-ldbm.h      |  68 ++++----
c04070
 ldap/servers/slapd/back-ldbm/backentry.c      |   2 +-
c04070
 ldap/servers/slapd/back-ldbm/cache.c          | 163 ++++++++++++++++--
c04070
 ldap/servers/slapd/back-ldbm/ldbm_add.c       |  13 ++
c04070
 ldap/servers/slapd/back-ldbm/ldbm_delete.c    |  12 ++
c04070
 ldap/servers/slapd/back-ldbm/ldbm_modify.c    |  12 ++
c04070
 ldap/servers/slapd/back-ldbm/ldbm_modrdn.c    |  22 ++-
c04070
 .../servers/slapd/back-ldbm/proto-back-ldbm.h |   1 +
c04070
 ldap/servers/slapd/slapi-plugin.h             |  15 ++
c04070
 ldap/servers/slapd/time.c                     |  26 +++
c04070
 12 files changed, 341 insertions(+), 53 deletions(-)
c04070
c04070
diff --git a/configure.ac b/configure.ac
c04070
index 91d6d398b..ea528ff2b 100644
c04070
--- a/configure.ac
c04070
+++ b/configure.ac
c04070
@@ -72,9 +72,6 @@ AC_FUNC_STRFTIME
c04070
 AC_FUNC_VPRINTF
c04070
 AC_CHECK_FUNCS([endpwent ftruncate getcwd gethostbyname inet_ntoa localtime_r memmove memset mkdir munmap putenv rmdir setrlimit socket strcasecmp strchr strcspn strdup strerror strncasecmp strpbrk strrchr strstr strtol tzset])
c04070
 
c04070
-# These functions are *required* without option.
c04070
-AC_CHECK_FUNCS([clock_gettime], [], AC_MSG_ERROR([unable to locate required symbol clock_gettime]))
c04070
-
c04070
 # This will detect if we need to add the LIBADD_DL value for us.
c04070
 LT_LIB_DLLOAD
c04070
 
c04070
diff --git a/dirsrvtests/tests/suites/betxns/betxn_test.py b/dirsrvtests/tests/suites/betxns/betxn_test.py
c04070
index 175496495..48181a9ea 100644
c04070
--- a/dirsrvtests/tests/suites/betxns/betxn_test.py
c04070
+++ b/dirsrvtests/tests/suites/betxns/betxn_test.py
c04070
@@ -8,6 +8,7 @@
c04070
 #
c04070
 import pytest
c04070
 import six
c04070
+import ldap
c04070
 from lib389.tasks import *
c04070
 from lib389.utils import *
c04070
 from lib389.topologies import topology_st
c04070
@@ -248,6 +249,62 @@ def test_betxn_memberof(topology_st, dynamic_plugins):
c04070
     log.info('test_betxn_memberof: PASSED')
c04070
 
c04070
 
c04070
+def test_betxn_modrdn_memberof(topology_st):
c04070
+    """Test modrdn operartions and memberOf
c04070
+
c04070
+    :id: 70d0b96e-b693-4bf7-bbf5-102a66ac5994
c04070
+
c04070
+    :setup: Standalone instance
c04070
+
c04070
+    :steps: 1. Enable and configure memberOf plugin
c04070
+            2. Set memberofgroupattr="member" and memberofAutoAddOC="nsContainer"
c04070
+            3. Create group and user outside of memberOf plugin scope
c04070
+            4. Do modrdn to move group into scope
c04070
+            5. Do modrdn to move group into scope (again)
c04070
+
c04070
+    :expectedresults:
c04070
+            1. memberOf plugin plugin should be ON
c04070
+            2. Set memberofgroupattr="member" and memberofAutoAddOC="nsContainer" should PASS
c04070
+            3. Creating group and user should PASS
c04070
+            4. Modrdn should fail with objectclass violation
c04070
+            5. Second modrdn should also fail with objectclass violation
c04070
+    """
c04070
+
c04070
+    peoplebase = 'ou=people,%s' % DEFAULT_SUFFIX
c04070
+    memberof = MemberOfPlugin(topology_st.standalone)
c04070
+    memberof.enable()
c04070
+    memberof.set_autoaddoc('nsContainer')  # Bad OC
c04070
+    memberof.set('memberOfEntryScope', peoplebase)
c04070
+    memberof.set('memberOfAllBackends', 'on')
c04070
+    topology_st.standalone.restart()
c04070
+
c04070
+    groups = Groups(topology_st.standalone, DEFAULT_SUFFIX)
c04070
+    group = groups.create(properties={
c04070
+        'cn': 'group',
c04070
+    })
c04070
+
c04070
+    # Create user and add it to group
c04070
+    users = UserAccounts(topology_st.standalone, basedn=DEFAULT_SUFFIX)
c04070
+    user = users.create(properties=TEST_USER_PROPERTIES)
c04070
+    if not ds_is_older('1.3.7'):
c04070
+        user.remove('objectClass', 'nsMemberOf')
c04070
+
c04070
+    group.add_member(user.dn)
c04070
+
c04070
+    # Attempt modrdn that should fail, but the original entry should stay in the cache
c04070
+    with pytest.raises(ldap.OBJECTCLASS_VIOLATION):
c04070
+        group.rename('cn=group_to_people', newsuperior=peoplebase)
c04070
+
c04070
+    # Should fail, but not with NO_SUCH_OBJECT as the original entry should still be in the cache
c04070
+    with pytest.raises(ldap.OBJECTCLASS_VIOLATION):
c04070
+        group.rename('cn=group_to_people', newsuperior=peoplebase)
c04070
+
c04070
+    #
c04070
+    # Done
c04070
+    #
c04070
+    log.info('test_betxn_modrdn_memberof: PASSED')
c04070
+
c04070
+
c04070
 if __name__ == '__main__':
c04070
     # Run isolated
c04070
     # -s for DEBUG mode
c04070
diff --git a/ldap/servers/slapd/back-ldbm/back-ldbm.h b/ldap/servers/slapd/back-ldbm/back-ldbm.h
c04070
index 4727961a9..399508561 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/back-ldbm.h
c04070
+++ b/ldap/servers/slapd/back-ldbm/back-ldbm.h
c04070
@@ -310,36 +310,37 @@ typedef struct
c04070
 #define CACHE_TYPE_ENTRY 0
c04070
 #define CACHE_TYPE_DN    1
c04070
 
c04070
-struct backcommon
c04070
-{
c04070
-    int ep_type;                   /* to distinguish backdn from backentry */
c04070
-    struct backcommon *ep_lrunext; /* for the cache */
c04070
-    struct backcommon *ep_lruprev; /* for the cache */
c04070
-    ID ep_id;                      /* entry id */
c04070
-    char ep_state;                 /* state in the cache */
c04070
-#define ENTRY_STATE_DELETED    0x1 /* entry is marked as deleted */
c04070
-#define ENTRY_STATE_CREATING   0x2 /* entry is being created; don't touch it */
c04070
-#define ENTRY_STATE_NOTINCACHE 0x4 /* cache_add failed; not in the cache */
c04070
-    int ep_refcnt;                 /* entry reference cnt */
c04070
-    size_t ep_size;                /* for cache tracking */
c04070
+struct backcommon {
c04070
+    int               ep_type;      /* to distinguish backdn from backentry */
c04070
+    struct backcommon *ep_lrunext;  /* for the cache */
c04070
+    struct backcommon *ep_lruprev;  /* for the cache */
c04070
+    ID                ep_id;        /* entry id */
c04070
+    char              ep_state;     /* state in the cache */
c04070
+#define ENTRY_STATE_DELETED     0x1 /* entry is marked as deleted */
c04070
+#define ENTRY_STATE_CREATING    0x2 /* entry is being created; don't touch it */
c04070
+#define ENTRY_STATE_NOTINCACHE  0x4 /* cache_add failed; not in the cache */
c04070
+#define ENTRY_STATE_INVALID     0x8 /* cache entry is invalid and needs to be removed */
c04070
+    int               ep_refcnt;    /* entry reference cnt */
c04070
+    size_t            ep_size;      /* for cache tracking */
c04070
+    struct timespec ep_create_time; /* the time the entry was added to the cache */
c04070
 };
c04070
 
c04070
 /* From ep_type through ep_size MUST be identical to backcommon */
c04070
-struct backentry
c04070
-{
c04070
-    int ep_type;                   /* to distinguish backdn from backentry */
c04070
-    struct backcommon *ep_lrunext; /* for the cache */
c04070
-    struct backcommon *ep_lruprev; /* for the cache */
c04070
-    ID ep_id;                      /* entry id */
c04070
-    char ep_state;                 /* state in the cache */
c04070
-    int ep_refcnt;                 /* entry reference cnt */
c04070
-    size_t ep_size;                /* for cache tracking */
c04070
-    Slapi_Entry *ep_entry;         /* real entry */
c04070
-    Slapi_Entry *ep_vlventry;
c04070
-    void *ep_dn_link;     /* linkage for the 3 hash */
c04070
-    void *ep_id_link;     /*     tables used for */
c04070
-    void *ep_uuid_link;   /*     looking up entries */
c04070
-    PRMonitor *ep_mutexp; /* protection for mods; make it reentrant */
c04070
+struct backentry {
c04070
+    int               ep_type;      /* to distinguish backdn from backentry */
c04070
+    struct backcommon *ep_lrunext;  /* for the cache */
c04070
+    struct backcommon *ep_lruprev;  /* for the cache */
c04070
+    ID                ep_id;        /* entry id */
c04070
+    char              ep_state;     /* state in the cache */
c04070
+    int               ep_refcnt;    /* entry reference cnt */
c04070
+    size_t            ep_size;      /* for cache tracking */
c04070
+    struct timespec ep_create_time; /* the time the entry was added to the cache */
c04070
+    Slapi_Entry       *ep_entry;    /* real entry */
c04070
+    Slapi_Entry       *ep_vlventry;
c04070
+    void *            ep_dn_link;   /* linkage for the 3 hash */
c04070
+    void *            ep_id_link;   /*     tables used for */
c04070
+    void *            ep_uuid_link; /*     looking up entries */
c04070
+    PRMonitor         *ep_mutexp;   /* protection for mods; make it reentrant */
c04070
 };
c04070
 
c04070
 /* From ep_type through ep_size MUST be identical to backcommon */
c04070
@@ -348,12 +349,13 @@ struct backdn
c04070
     int ep_type;                   /* to distinguish backdn from backentry */
c04070
     struct backcommon *ep_lrunext; /* for the cache */
c04070
     struct backcommon *ep_lruprev; /* for the cache */
c04070
-    ID ep_id;                      /* entry id */
c04070
-    char ep_state;                 /* state in the cache; share ENTRY_STATE_* */
c04070
-    int ep_refcnt;                 /* entry reference cnt */
c04070
-    size_t ep_size;                /* for cache tracking */
c04070
-    Slapi_DN *dn_sdn;
c04070
-    void *dn_id_link; /* for hash table */
c04070
+    ID                ep_id;       /* entry id */
c04070
+    char              ep_state;    /* state in the cache; share ENTRY_STATE_* */
c04070
+    int               ep_refcnt;   /* entry reference cnt */
c04070
+    size_t            ep_size;      /* for cache tracking */
c04070
+    struct timespec ep_create_time; /* the time the entry was added to the cache */
c04070
+    Slapi_DN          *dn_sdn;
c04070
+    void              *dn_id_link; /* for hash table */
c04070
 };
c04070
 
c04070
 /* for the in-core cache of entries */
c04070
diff --git a/ldap/servers/slapd/back-ldbm/backentry.c b/ldap/servers/slapd/back-ldbm/backentry.c
c04070
index f2fe780db..a1f3ca1bb 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/backentry.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/backentry.c
c04070
@@ -23,7 +23,7 @@ backentry_free(struct backentry **bep)
c04070
         return;
c04070
     }
c04070
     ep = *bep;
c04070
-    PR_ASSERT(ep->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_NOTINCACHE));
c04070
+    PR_ASSERT(ep->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_NOTINCACHE | ENTRY_STATE_INVALID));
c04070
     if (ep->ep_entry != NULL) {
c04070
         slapi_entry_free(ep->ep_entry);
c04070
     }
c04070
diff --git a/ldap/servers/slapd/back-ldbm/cache.c b/ldap/servers/slapd/back-ldbm/cache.c
c04070
index 86e1f7b39..054766df2 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/cache.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/cache.c
c04070
@@ -56,6 +56,11 @@
c04070
 #define LOG(...)
c04070
 #endif
c04070
 
c04070
+typedef enum {
c04070
+    ENTRY_CACHE,
c04070
+    DN_CACHE,
c04070
+} CacheType;
c04070
+
c04070
 #define LRU_DETACH(cache, e) lru_detach((cache), (void *)(e))
c04070
 
c04070
 #define CACHE_LRU_HEAD(cache, type) ((type)((cache)->c_lruhead))
c04070
@@ -185,6 +190,7 @@ new_hash(u_long size, u_long offset, HashFn hfn, HashTestFn tfn)
c04070
 int
c04070
 add_hash(Hashtable *ht, void *key, uint32_t keylen, void *entry, void **alt)
c04070
 {
c04070
+    struct backcommon *back_entry = (struct backcommon *)entry;
c04070
     u_long val, slot;
c04070
     void *e;
c04070
 
c04070
@@ -202,6 +208,7 @@ add_hash(Hashtable *ht, void *key, uint32_t keylen, void *entry, void **alt)
c04070
         e = HASH_NEXT(ht, e);
c04070
     }
c04070
     /* ok, it's not already there, so add it */
c04070
+    back_entry->ep_create_time = slapi_current_rel_time_hr();
c04070
     HASH_NEXT(ht, entry) = ht->slot[slot];
c04070
     ht->slot[slot] = entry;
c04070
     return 1;
c04070
@@ -492,6 +499,126 @@ cache_make_hashes(struct cache *cache, int type)
c04070
     }
c04070
 }
c04070
 
c04070
+/*
c04070
+ * Helper function for flush_hash() to calculate if the entry should be
c04070
+ * removed from the cache.
c04070
+ */
c04070
+static int32_t
c04070
+flush_remove_entry(struct timespec *entry_time, struct timespec *start_time)
c04070
+{
c04070
+    struct timespec diff;
c04070
+
c04070
+    slapi_timespec_diff(entry_time, start_time, &diff);
c04070
+    if (diff.tv_sec >= 0) {
c04070
+        return 1;
c04070
+    } else {
c04070
+        return 0;
c04070
+    }
c04070
+}
c04070
+
c04070
+/*
c04070
+ * Flush all the cache entries that were added after the "start time"
c04070
+ * This is called when a backend transaction plugin fails, and we need
c04070
+ * to remove all the possible invalid entries in the cache.
c04070
+ *
c04070
+ * If the ref count is 0, we can straight up remove it from the cache, but
c04070
+ * if the ref count is greater than 1, then the entry is currently in use.
c04070
+ * In the later case we set the entry state to ENTRY_STATE_INVALID, and
c04070
+ * when the owning thread cache_returns() the cache entry is automatically
c04070
+ * removed so another thread can not use/lock the invalid cache entry.
c04070
+ */
c04070
+static void
c04070
+flush_hash(struct cache *cache, struct timespec *start_time, int32_t type)
c04070
+{
c04070
+    Hashtable *ht = cache->c_idtable; /* start with the ID table as it's in both ENTRY and DN caches */
c04070
+    void *e, *laste = NULL;
c04070
+
c04070
+    cache_lock(cache);
c04070
+
c04070
+    for (size_t i = 0; i < ht->size; i++) {
c04070
+        e = ht->slot[i];
c04070
+        while (e) {
c04070
+            struct backcommon *entry = (struct backcommon *)e;
c04070
+            uint64_t remove_it = 0;
c04070
+            if (flush_remove_entry(&entry->ep_create_time, start_time)) {
c04070
+                /* Mark the entry to be removed */
c04070
+                slapi_log_err(SLAPI_LOG_CACHE, "flush_hash", "[%s] Removing entry id (%d)\n",
c04070
+                        type ? "DN CACHE" : "ENTRY CACHE", entry->ep_id);
c04070
+                remove_it = 1;
c04070
+            }
c04070
+            laste = e;
c04070
+            e = HASH_NEXT(ht, e);
c04070
+
c04070
+            if (remove_it) {
c04070
+                /* since we have the cache lock we know we can trust refcnt */
c04070
+                entry->ep_state |= ENTRY_STATE_INVALID;
c04070
+                if (entry->ep_refcnt == 0) {
c04070
+                    entry->ep_refcnt++;
c04070
+                    lru_delete(cache, laste);
c04070
+                    if (type == ENTRY_CACHE) {
c04070
+                        entrycache_remove_int(cache, laste);
c04070
+                        entrycache_return(cache, (struct backentry **)&laste);
c04070
+                    } else {
c04070
+                        dncache_remove_int(cache, laste);
c04070
+                        dncache_return(cache, (struct backdn **)&laste);
c04070
+                    }
c04070
+                } else {
c04070
+                    /* Entry flagged for removal */
c04070
+                    slapi_log_err(SLAPI_LOG_CACHE, "flush_hash",
c04070
+                            "[%s] Flagging entry to be removed later: id (%d) refcnt: %d\n",
c04070
+                            type ? "DN CACHE" : "ENTRY CACHE", entry->ep_id, entry->ep_refcnt);
c04070
+                }
c04070
+            }
c04070
+        }
c04070
+    }
c04070
+
c04070
+    if (type == ENTRY_CACHE) {
c04070
+        /* Also check the DN hashtable */
c04070
+        ht = cache->c_dntable;
c04070
+
c04070
+        for (size_t i = 0; i < ht->size; i++) {
c04070
+            e = ht->slot[i];
c04070
+            while (e) {
c04070
+                struct backcommon *entry = (struct backcommon *)e;
c04070
+                uint64_t remove_it = 0;
c04070
+                if (flush_remove_entry(&entry->ep_create_time, start_time)) {
c04070
+                    /* Mark the entry to be removed */
c04070
+                    slapi_log_err(SLAPI_LOG_CACHE, "flush_hash", "[ENTRY CACHE] Removing entry id (%d)\n",
c04070
+                            entry->ep_id);
c04070
+                    remove_it = 1;
c04070
+                }
c04070
+                laste = e;
c04070
+                e = HASH_NEXT(ht, e);
c04070
+
c04070
+                if (remove_it) {
c04070
+                    /* since we have the cache lock we know we can trust refcnt */
c04070
+                    entry->ep_state |= ENTRY_STATE_INVALID;
c04070
+                    if (entry->ep_refcnt == 0) {
c04070
+                        entry->ep_refcnt++;
c04070
+                        lru_delete(cache, laste);
c04070
+                        entrycache_remove_int(cache, laste);
c04070
+                        entrycache_return(cache, (struct backentry **)&laste);
c04070
+                    } else {
c04070
+                        /* Entry flagged for removal */
c04070
+                        slapi_log_err(SLAPI_LOG_CACHE, "flush_hash",
c04070
+                                "[ENTRY CACHE] Flagging entry to be removed later: id (%d) refcnt: %d\n",
c04070
+                                entry->ep_id, entry->ep_refcnt);
c04070
+                    }
c04070
+                }
c04070
+            }
c04070
+        }
c04070
+    }
c04070
+
c04070
+    cache_unlock(cache);
c04070
+}
c04070
+
c04070
+void
c04070
+revert_cache(ldbm_instance *inst, struct timespec *start_time)
c04070
+{
c04070
+    flush_hash(&inst->inst_cache, start_time, ENTRY_CACHE);
c04070
+    flush_hash(&inst->inst_dncache, start_time, DN_CACHE);
c04070
+}
c04070
+
c04070
 /* initialize the cache */
c04070
 int
c04070
 cache_init(struct cache *cache, uint64_t maxsize, long maxentries, int type)
c04070
@@ -1141,10 +1268,10 @@ entrycache_return(struct cache *cache, struct backentry **bep)
c04070
         backentry_free(bep);
c04070
     } else {
c04070
         ASSERT(e->ep_refcnt > 0);
c04070
-        if (!--e->ep_refcnt) {
c04070
-            if (e->ep_state & ENTRY_STATE_DELETED) {
c04070
-                const char *ndn = slapi_sdn_get_ndn(backentry_get_sdn(e));
c04070
-                if (ndn) {
c04070
+        if (! --e->ep_refcnt) {
c04070
+            if (e->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_INVALID)) {
c04070
+                const char* ndn = slapi_sdn_get_ndn(backentry_get_sdn(e));
c04070
+                if (ndn){
c04070
                     /*
c04070
                      * State is "deleted" and there are no more references,
c04070
                      * so we need to remove the entry from the DN cache because
c04070
@@ -1154,6 +1281,13 @@ entrycache_return(struct cache *cache, struct backentry **bep)
c04070
                         LOG("entrycache_return -Failed to remove %s from dn table\n", ndn);
c04070
                     }
c04070
                 }
c04070
+                if (e->ep_state & ENTRY_STATE_INVALID) {
c04070
+                    /* Remove it from the hash table before we free the back entry */
c04070
+                    slapi_log_err(SLAPI_LOG_CACHE, "entrycache_return",
c04070
+                            "Finally flushing invalid entry: %d (%s)\n",
c04070
+                            e->ep_id, backentry_get_ndn(e));
c04070
+                    entrycache_remove_int(cache, e);
c04070
+                }
c04070
                 backentry_free(bep);
c04070
             } else {
c04070
                 lru_add(cache, e);
c04070
@@ -1535,11 +1669,11 @@ cache_lock_entry(struct cache *cache, struct backentry *e)
c04070
 
c04070
     /* make sure entry hasn't been deleted now */
c04070
     cache_lock(cache);
c04070
-    if (e->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_NOTINCACHE)) {
c04070
-        cache_unlock(cache);
c04070
-        PR_ExitMonitor(e->ep_mutexp);
c04070
-        LOG("<= cache_lock_entry (DELETED)\n");
c04070
-        return RETRY_CACHE_LOCK;
c04070
+    if (e->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_NOTINCACHE | ENTRY_STATE_INVALID)) {
c04070
+       cache_unlock(cache);
c04070
+       PR_ExitMonitor(e->ep_mutexp);
c04070
+       LOG("<= cache_lock_entry (DELETED)\n");
c04070
+       return RETRY_CACHE_LOCK;
c04070
     }
c04070
     cache_unlock(cache);
c04070
 
c04070
@@ -1695,8 +1829,15 @@ dncache_return(struct cache *cache, struct backdn **bdn)
c04070
         backdn_free(bdn);
c04070
     } else {
c04070
         ASSERT((*bdn)->ep_refcnt > 0);
c04070
-        if (!--(*bdn)->ep_refcnt) {
c04070
-            if ((*bdn)->ep_state & ENTRY_STATE_DELETED) {
c04070
+        if (! --(*bdn)->ep_refcnt) {
c04070
+            if ((*bdn)->ep_state & (ENTRY_STATE_DELETED | ENTRY_STATE_INVALID)) {
c04070
+                if ((*bdn)->ep_state & ENTRY_STATE_INVALID) {
c04070
+                    /* Remove it from the hash table before we free the back dn */
c04070
+                    slapi_log_err(SLAPI_LOG_CACHE, "dncache_return",
c04070
+                            "Finally flushing invalid entry: %d (%s)\n",
c04070
+                            (*bdn)->ep_id, slapi_sdn_get_dn((*bdn)->dn_sdn));
c04070
+                    dncache_remove_int(cache, (*bdn));
c04070
+                }
c04070
                 backdn_free(bdn);
c04070
             } else {
c04070
                 lru_add(cache, (void *)*bdn);
c04070
diff --git a/ldap/servers/slapd/back-ldbm/ldbm_add.c b/ldap/servers/slapd/back-ldbm/ldbm_add.c
c04070
index 32c8e71ff..d3c8cdab2 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/ldbm_add.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/ldbm_add.c
c04070
@@ -97,6 +97,8 @@ ldbm_back_add(Slapi_PBlock *pb)
c04070
     PRUint64 conn_id;
c04070
     int op_id;
c04070
     int result_sent = 0;
c04070
+    int32_t parent_op = 0;
c04070
+    struct timespec parent_time;
c04070
 
c04070
     if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
c04070
         conn_id = 0; /* connection is NULL */
c04070
@@ -147,6 +149,13 @@ ldbm_back_add(Slapi_PBlock *pb)
c04070
     slapi_entry_delete_values(e, numsubordinates, NULL);
c04070
 
c04070
     dblayer_txn_init(li, &txn);
c04070
+
c04070
+    if (txn.back_txn_txn == NULL) {
c04070
+        /* This is the parent operation, get the time */
c04070
+        parent_op = 1;
c04070
+        parent_time = slapi_current_rel_time_hr();
c04070
+    }
c04070
+
c04070
     /* the calls to perform searches require the parent txn if any
c04070
        so set txn to the parent_txn until we begin the child transaction */
c04070
     if (parent_txn) {
c04070
@@ -1239,6 +1248,10 @@ ldbm_back_add(Slapi_PBlock *pb)
c04070
     goto common_return;
c04070
 
c04070
 error_return:
c04070
+    if (parent_op) {
c04070
+        revert_cache(inst, &parent_time);
c04070
+    }
c04070
+
c04070
     if (addingentry_id_assigned) {
c04070
         next_id_return(be, addingentry->ep_id);
c04070
     }
c04070
diff --git a/ldap/servers/slapd/back-ldbm/ldbm_delete.c b/ldap/servers/slapd/back-ldbm/ldbm_delete.c
c04070
index f5f6c1e3a..80c53a3e0 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/ldbm_delete.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/ldbm_delete.c
c04070
@@ -79,6 +79,8 @@ ldbm_back_delete(Slapi_PBlock *pb)
c04070
     ID tomb_ep_id = 0;
c04070
     int result_sent = 0;
c04070
     Connection *pb_conn;
c04070
+    int32_t parent_op = 0;
c04070
+    struct timespec parent_time;
c04070
 
c04070
     if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
c04070
         conn_id = 0; /* connection is NULL */
c04070
@@ -98,6 +100,13 @@ ldbm_back_delete(Slapi_PBlock *pb)
c04070
 
c04070
     /* dblayer_txn_init needs to be called before "goto error_return" */
c04070
     dblayer_txn_init(li, &txn);
c04070
+
c04070
+    if (txn.back_txn_txn == NULL) {
c04070
+        /* This is the parent operation, get the time */
c04070
+        parent_op = 1;
c04070
+        parent_time = slapi_current_rel_time_hr();
c04070
+    }
c04070
+
c04070
     /* the calls to perform searches require the parent txn if any
c04070
        so set txn to the parent_txn until we begin the child transaction */
c04070
     if (parent_txn) {
c04070
@@ -1356,6 +1365,9 @@ commit_return:
c04070
     goto common_return;
c04070
 
c04070
 error_return:
c04070
+    if (parent_op) {
c04070
+        revert_cache(inst, &parent_time);
c04070
+    }
c04070
     if (tombstone) {
c04070
         if (cache_is_in_cache(&inst->inst_cache, tombstone)) {
c04070
             tomb_ep_id = tombstone->ep_id; /* Otherwise, tombstone might have been freed. */
c04070
diff --git a/ldap/servers/slapd/back-ldbm/ldbm_modify.c b/ldap/servers/slapd/back-ldbm/ldbm_modify.c
c04070
index cc4319e5f..93ab0a9e8 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/ldbm_modify.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/ldbm_modify.c
c04070
@@ -412,6 +412,8 @@ ldbm_back_modify(Slapi_PBlock *pb)
c04070
     int fixup_tombstone = 0;
c04070
     int ec_locked = 0;
c04070
     int result_sent = 0;
c04070
+    int32_t parent_op = 0;
c04070
+    struct timespec parent_time;
c04070
 
c04070
     slapi_pblock_get(pb, SLAPI_BACKEND, &be);
c04070
     slapi_pblock_get(pb, SLAPI_PLUGIN_PRIVATE, &li;;
c04070
@@ -424,6 +426,13 @@ ldbm_back_modify(Slapi_PBlock *pb)
c04070
     fixup_tombstone = operation_is_flag_set(operation, OP_FLAG_TOMBSTONE_FIXUP);
c04070
 
c04070
     dblayer_txn_init(li, &txn); /* must do this before first goto error_return */
c04070
+
c04070
+    if (txn.back_txn_txn == NULL) {
c04070
+        /* This is the parent operation, get the time */
c04070
+        parent_op = 1;
c04070
+        parent_time = slapi_current_rel_time_hr();
c04070
+    }
c04070
+
c04070
     /* the calls to perform searches require the parent txn if any
c04070
        so set txn to the parent_txn until we begin the child transaction */
c04070
     if (parent_txn) {
c04070
@@ -887,6 +896,9 @@ ldbm_back_modify(Slapi_PBlock *pb)
c04070
     goto common_return;
c04070
 
c04070
 error_return:
c04070
+    if (parent_op) {
c04070
+        revert_cache(inst, &parent_time);
c04070
+    }
c04070
     if (postentry != NULL) {
c04070
         slapi_entry_free(postentry);
c04070
         postentry = NULL;
c04070
diff --git a/ldap/servers/slapd/back-ldbm/ldbm_modrdn.c b/ldap/servers/slapd/back-ldbm/ldbm_modrdn.c
c04070
index e2e9d1b46..1ca1bdb28 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/ldbm_modrdn.c
c04070
+++ b/ldap/servers/slapd/back-ldbm/ldbm_modrdn.c
c04070
@@ -97,6 +97,8 @@ ldbm_back_modrdn(Slapi_PBlock *pb)
c04070
     int op_id;
c04070
     int result_sent = 0;
c04070
     Connection *pb_conn = NULL;
c04070
+    int32_t parent_op = 0;
c04070
+    struct timespec parent_time;
c04070
 
c04070
     if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
c04070
         conn_id = 0; /* connection is NULL */
c04070
@@ -134,6 +136,13 @@ ldbm_back_modrdn(Slapi_PBlock *pb)
c04070
 
c04070
     /* dblayer_txn_init needs to be called before "goto error_return" */
c04070
     dblayer_txn_init(li, &txn);
c04070
+
c04070
+    if (txn.back_txn_txn == NULL) {
c04070
+        /* This is the parent operation, get the time */
c04070
+        parent_op = 1;
c04070
+        parent_time = slapi_current_rel_time_hr();
c04070
+    }
c04070
+
c04070
     /* the calls to perform searches require the parent txn if any
c04070
        so set txn to the parent_txn until we begin the child transaction */
c04070
     if (parent_txn) {
c04070
@@ -1276,6 +1285,10 @@ ldbm_back_modrdn(Slapi_PBlock *pb)
c04070
     goto common_return;
c04070
 
c04070
 error_return:
c04070
+    /* Revert the caches if this is the parent operation */
c04070
+    if (parent_op) {
c04070
+       revert_cache(inst, &parent_time);
c04070
+    }
c04070
     /* result already sent above - just free stuff */
c04070
     if (postentry) {
c04070
         slapi_entry_free(postentry);
c04070
@@ -1353,6 +1366,10 @@ error_return:
c04070
                     slapi_pblock_set(pb, SLAPI_PLUGIN_OPRETURN, ldap_result_code ? &ldap_result_code : &retval);
c04070
                 }
c04070
                 slapi_pblock_get(pb, SLAPI_PB_RESULT_TEXT, &ldap_result_message);
c04070
+                /* Revert the caches if this is the parent operation */
c04070
+                if (parent_op) {
c04070
+                    revert_cache(inst, &parent_time);
c04070
+                }
c04070
             }
c04070
 	retval = plugin_call_mmr_plugin_postop(pb, NULL,SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN);
c04070
 
c04070
@@ -1413,12 +1430,7 @@ common_return:
c04070
             CACHE_RETURN(&inst->inst_dncache, &bdn;;
c04070
         }
c04070
 
c04070
-        /* remove the new entry from the cache if the op failed -
c04070
-           otherwise, leave it in */
c04070
         if (ec && inst) {
c04070
-            if (retval && cache_is_in_cache(&inst->inst_cache, ec)) {
c04070
-                CACHE_REMOVE(&inst->inst_cache, ec);
c04070
-            }
c04070
             CACHE_RETURN(&inst->inst_cache, &ec);
c04070
         }
c04070
         ec = NULL;
c04070
diff --git a/ldap/servers/slapd/back-ldbm/proto-back-ldbm.h b/ldap/servers/slapd/back-ldbm/proto-back-ldbm.h
c04070
index 61c3313c5..510d38f57 100644
c04070
--- a/ldap/servers/slapd/back-ldbm/proto-back-ldbm.h
c04070
+++ b/ldap/servers/slapd/back-ldbm/proto-back-ldbm.h
c04070
@@ -55,6 +55,7 @@ void cache_unlock_entry(struct cache *cache, struct backentry *e);
c04070
 int cache_replace(struct cache *cache, void *oldptr, void *newptr);
c04070
 int cache_has_otherref(struct cache *cache, void *bep);
c04070
 int cache_is_in_cache(struct cache *cache, void *ptr);
c04070
+void revert_cache(ldbm_instance *inst, struct timespec *start_time);
c04070
 
c04070
 #ifdef CACHE_DEBUG
c04070
 void check_entry_cache(struct cache *cache, struct backentry *e);
c04070
diff --git a/ldap/servers/slapd/slapi-plugin.h b/ldap/servers/slapd/slapi-plugin.h
c04070
index bdad4e59e..eefe88724 100644
c04070
--- a/ldap/servers/slapd/slapi-plugin.h
c04070
+++ b/ldap/servers/slapd/slapi-plugin.h
c04070
@@ -6853,6 +6853,12 @@ void slapi_operation_time_expiry(Slapi_Operation *o, time_t timeout, struct time
c04070
  */
c04070
 slapi_timer_result slapi_timespec_expire_check(struct timespec *expire);
c04070
 
c04070
+/**
c04070
+ * Returns the current system time as a hr clock
c04070
+ *
c04070
+ * \return timespec of the current monotonic time.
c04070
+ */
c04070
+struct timespec slapi_current_rel_time_hr(void);
c04070
 
c04070
 /*
c04070
  * Plugin and parameter block related macros (remainder of this file).
c04070
@@ -8296,6 +8302,15 @@ uint64_t slapi_atomic_decr_64(uint64_t *ptr, int memorder);
c04070
 
c04070
 /* helper function */
c04070
 const char * fetch_attr(Slapi_Entry *e, const char *attrname, char *default_val);
c04070
+/**
c04070
+ * Diffs two timespects a - b into *diff. This is useful with
c04070
+ * clock_monotonic to find time taken to perform operations.
c04070
+ *
c04070
+ * \param struct timespec a the "end" time.
c04070
+ * \param struct timespec b the "start" time.
c04070
+ * \param struct timespec c the difference.
c04070
+ */
c04070
+void slapi_timespec_diff(struct timespec *a, struct timespec *b, struct timespec *diff);
c04070
 
c04070
 #ifdef __cplusplus
c04070
 }
c04070
diff --git a/ldap/servers/slapd/time.c b/ldap/servers/slapd/time.c
c04070
index 584bd1e63..2a3865858 100644
c04070
--- a/ldap/servers/slapd/time.c
c04070
+++ b/ldap/servers/slapd/time.c
c04070
@@ -96,6 +96,32 @@ slapi_current_utc_time_hr(void)
c04070
     return ltnow;
c04070
 }
c04070
 
c04070
+struct timespec
c04070
+slapi_current_rel_time_hr(void)
c04070
+{
c04070
+    struct timespec now;
c04070
+    clock_gettime(CLOCK_MONOTONIC, &now;;
c04070
+    return now;
c04070
+}
c04070
+
c04070
+void
c04070
+slapi_timespec_diff(struct timespec *a, struct timespec *b, struct timespec *diff)
c04070
+{
c04070
+    /* Now diff the two */
c04070
+    time_t sec = a->tv_sec - b->tv_sec;
c04070
+    int32_t nsec = a->tv_nsec - b->tv_nsec;
c04070
+
c04070
+    if (nsec < 0) {
c04070
+        /* It's negative so take one second */
c04070
+        sec -= 1;
c04070
+        /* And set nsec to to a whole value */
c04070
+        nsec = 1000000000 - nsec;
c04070
+    }
c04070
+
c04070
+    diff->tv_sec = sec;
c04070
+    diff->tv_nsec = nsec;
c04070
+}
c04070
+
c04070
 time_t
c04070
 slapi_current_utc_time(void)
c04070
 {
c04070
-- 
c04070
2.21.0
c04070