Ticket #47834 - Tombstone_to_glue: if parents are also converted to glue, the target entry's DN must be adjusted.

Bug description: tombstone_to_glue resolves parents recursively if
they are also a tombstone entry, which may change the DN of the
target entry, but the DN change was not adjusted.

Fix description: Added a new argument newparentdn to tombstone_to_
glue_resolve_parent to return the new parent DN if it has been updated.
If a new parent DN is returned, set it to the target DN.

This patch also adds a cache debugging function: check_entry_cache,
which is disabled by default (in #ifdef CACHE_DEBUG)

Note: this bug is a left over of ticket #47750.

https://fedorahosted.org/389/ticket/47834

Reviewed by [email protected] (Thank you, Rich!!)

ldap/servers/plugins/replication/urp.c

@@ -966,7 +966,8 @@ urp_add_resolve_parententry (Slapi_PBlock *pb, char *sessionid, Slapi_Entry *ent
 	if(is_tombstone_entry(parententry)) /* The parent is a tombstone */
 	{
 		/* The parent entry must be resurected from the dead. */
-		ldap_rc = tombstone_to_glue (pb, sessionid, parententry, parentdn, REASON_RESURRECT_ENTRY, opcsn);
+		/* parentdn retrieved from entry is not tombstone dn. */
+		ldap_rc = tombstone_to_glue (pb, sessionid, parententry, parentdn, REASON_RESURRECT_ENTRY, opcsn, NULL);
 		if ( ldap_rc != LDAP_SUCCESS )
 		{
 			ldap_rc= LDAP_OPERATIONS_ERROR;

ldap/servers/plugins/replication/urp.h

@@ -79,6 +79,6 @@ PRBool get_glue_csn(const Slapi_Entry *entry, const CSN **gluecsn);
  * urp_tombstone.c
  */
 int is_tombstone_entry(const Slapi_Entry* entry);
-int tombstone_to_glue(Slapi_PBlock *pb, char *sessionid, Slapi_Entry *entry, const Slapi_DN *parentdn, const char *reason, CSN *opcsn);
+int tombstone_to_glue(Slapi_PBlock *pb, char *sessionid, Slapi_Entry *entry, const Slapi_DN *parentdn, const char *reason, CSN *opcsn,     Slapi_DN **newparentdn);
 int entry_to_tombstone ( Slapi_PBlock *pb, Slapi_Entry *entry );
 PRBool get_tombstone_csn(const Slapi_Entry *entry, const CSN **delcsn);

ldap/servers/plugins/replication/urp_glue.c

@@ -230,7 +230,7 @@ create_glue_entry ( Slapi_PBlock *pb, char *sessionid, Slapi_DN *dn, const char
 
 		slapi_pblock_get( pb, SLAPI_BACKEND, &backend );
 		slapi_sdn_get_backend_parent ( dn, superiordn, backend );
-		slapi_rdn_set_dn_ext(rdn, slapi_sdn_get_dn(dn), 1/* skip nsuniqeid=..., in dn */);
+		slapi_rdn_set_dn_ext(rdn, slapi_sdn_get_dn(dn), SLAPI_RDN_SET_DN_SKIP_UNIQUEID);
 
 		while(!done)
 		{

ldap/servers/plugins/replication/urp_tombstone.c

@@ -87,17 +87,18 @@ tombstone_to_glue_resolve_parent (
 	char *sessionid,
 	const Slapi_DN *parentdn,
 	const char *parentuniqueid,
-	CSN *opcsn)
+	CSN *opcsn,
+	Slapi_DN **newparentdn)
 {
 	/* Let's have a look at the parent of this entry... */
 	if(!slapi_sdn_isempty(parentdn) && parentuniqueid!=NULL)
 	{
 		int op_result;
-	    Slapi_PBlock *newpb= slapi_pblock_new();
-	    slapi_search_internal_set_pb(
-	    			newpb,
-	    			slapi_sdn_get_dn(parentdn), /* JCM - This DN just identifies the backend to be searched. */
-	    			LDAP_SCOPE_BASE,
+		Slapi_PBlock *newpb= slapi_pblock_new();
+		slapi_search_internal_set_pb(
+					newpb,
+					slapi_sdn_get_dn(parentdn), /* JCM - This DN just identifies the backend to be searched. */
+					LDAP_SCOPE_BASE,
 					"objectclass=*",
 					NULL, /*attrs*/
 					0, /*attrsonly*/
@@ -106,7 +107,7 @@ tombstone_to_glue_resolve_parent (
 					repl_get_plugin_identity(PLUGIN_MULTIMASTER_REPLICATION),
 					0);
 		slapi_search_internal_pb(newpb); 
-	    slapi_pblock_get(newpb, SLAPI_PLUGIN_INTOP_RESULT, &op_result);
+		slapi_pblock_get(newpb, SLAPI_PLUGIN_INTOP_RESULT, &op_result);
 		switch(op_result)
 		{
 		case LDAP_SUCCESS:
@@ -118,7 +119,8 @@ tombstone_to_glue_resolve_parent (
 			{
 				if(is_tombstone_entry(entries[0]))
 				{
-					tombstone_to_glue (pb, sessionid, entries[0], parentdn, REASON_RESURRECT_ENTRY, opcsn);
+					tombstone_to_glue(pb, sessionid, entries[0], parentdn,
+					                  REASON_RESURRECT_ENTRY, opcsn, newparentdn);
 				}
 			}
 			else
@@ -146,14 +148,16 @@ tombstone_to_glue (
 	Slapi_PBlock *pb,
 	char *sessionid,
 	Slapi_Entry *tombstoneentry,
-	const Slapi_DN *tombstonedn,
+	const Slapi_DN *gluedn, /* does not start with uniqueid= */
 	const char *reason,
-	CSN *opcsn)
+	CSN *opcsn,
+	Slapi_DN **newparentdn)
 {
 	Slapi_DN *parentdn;
 	char *parentuniqueid;
 	const char *tombstoneuniqueid;
-	Slapi_Entry *addingentry;
+	Slapi_Entry *addingentry = NULL;
+	Slapi_Entry *addingentry_bakup = NULL;
 	const char *addingdn;
 	int op_result;
 	int rdn_is_conflict = 0;
@@ -164,23 +168,35 @@ tombstone_to_glue (
 	 * must attach the entry to the Operation
 	 */
 
-
 	/* Resurrect the parent entry first */ 
 
 	/* JCM - This DN calculation is odd. It could resolve to NULL
 	 * which won't help us identify the correct backend to search.
 	 */
-	is_suffix_dn_ext (pb, tombstonedn, &parentdn, 1 /* is_tombstone */);
-	parentuniqueid= slapi_entry_attr_get_charptr (tombstoneentry, SLAPI_ATTR_VALUE_PARENT_UNIQUEID); /* Allocated */
-	tombstone_to_glue_resolve_parent (pb, sessionid, parentdn, parentuniqueid, opcsn);
+	is_suffix_dn_ext (pb, gluedn, &parentdn, 1 /* is_tombstone */);
+	parentuniqueid = slapi_entry_attr_get_charptr (tombstoneentry, SLAPI_ATTR_VALUE_PARENT_UNIQUEID); /* Allocated */
+	tombstone_to_glue_resolve_parent (pb, sessionid, parentdn, parentuniqueid, opcsn, newparentdn);
 
 	/* Submit an Add operation to turn the tombstone entry into glue. */
 	/*
 	 * The tombstone is stored with an invalid DN, we must fix this.
 	 */
 	addingentry = slapi_entry_dup(tombstoneentry);
-	addingdn = slapi_sdn_get_dn(tombstonedn);
-	slapi_entry_set_sdn(addingentry, tombstonedn);
+
+	if (newparentdn && *newparentdn && slapi_sdn_compare(parentdn, *newparentdn)) {
+		/* If the parents are resolved, the tombstone's DN is going to be different... */
+		/* Update DN in addingentry */
+		Slapi_RDN *rdn = slapi_rdn_new();
+		slapi_rdn_set_dn_ext(rdn, slapi_sdn_get_dn(gluedn), SLAPI_RDN_SET_DN_INCLUDE_UNIQUEID);
+		addingdn = slapi_moddn_get_newdn(slapi_entry_get_sdn(addingentry), slapi_rdn_get_rdn(rdn),
+		                                 slapi_sdn_get_dn(*newparentdn));
+		slapi_rdn_free(&rdn);
+		slapi_sdn_init_normdn_passin(*newparentdn, addingdn); /* to return the new parentdn to the caller */
+	} else {
+		slapi_sdn_free(newparentdn); /* no change in parentdn; returning NULL */
+		addingdn = slapi_sdn_get_dn(gluedn);
+	}
+	slapi_sdn_set_normdn_byval(slapi_entry_get_sdn(addingentry), addingdn);
 	/* not just e_sdn, e_rsdn needs to be updated. */
 	slapi_rdn_set_all_dn(slapi_entry_get_srdn(addingentry), slapi_entry_get_dn_const(addingentry));
 	rdn_is_conflict = slapi_rdn_is_conflict(slapi_entry_get_srdn(addingentry));
@@ -198,6 +214,7 @@ tombstone_to_glue (
 	 * tombstoneentry from DB/entry cache is duplicated and turned to be a glue.
 	 * This addingentry is freed in op_shared_add.
 	 */
+	addingentry_bakup = slapi_entry_dup(addingentry);
 	op_result = urp_fixup_add_entry (addingentry, tombstoneuniqueid, slapi_ch_strdup(parentuniqueid), opcsn, OP_FLAG_RESURECT_ENTRY);
 	if ((LDAP_ALREADY_EXISTS == op_result) && !rdn_is_conflict) {
 		/* conflict -- there's already the same named entry added.
@@ -207,7 +224,8 @@ tombstone_to_glue (
 		 * */
 		char *conflictrdn = get_rdn_plus_uniqueid(sessionid, addingdn, tombstoneuniqueid);
 		if (conflictrdn) {
-			addingentry = slapi_entry_dup(tombstoneentry);
+			addingentry = addingentry_bakup;
+			addingentry_bakup = NULL;
 			if (!slapi_entry_attr_hasvalue(addingentry, ATTR_NSDS5_REPLCONFLICT, reason)) {
 				/* Add the reason of turning it to glue - The backend code will use it*/
 				slapi_entry_add_string(addingentry, ATTR_NSDS5_REPLCONFLICT, reason);
@@ -223,15 +241,16 @@ tombstone_to_glue (
 			addingentry = NULL;
 		}
 	}
+	slapi_entry_free(addingentry_bakup);
 	slapi_ch_free_string(&parentuniqueid);
 	if (op_result == LDAP_SUCCESS)
 	{
-		slapi_log_error (slapi_log_urp, repl_plugin_name,
+		slapi_log_error (/*slapi_log_urp*/SLAPI_LOG_FATAL, repl_plugin_name,
 			"%s: Resurrected tombstone %s to glue reason '%s'\n", sessionid, addingdn, reason);
 	}
 	else if (LDAP_ALREADY_EXISTS == op_result)
 	{
-		slapi_log_error(slapi_log_urp, repl_plugin_name,
+		slapi_log_error(/*slapi_log_urp*/SLAPI_LOG_FATAL, repl_plugin_name,
 		                "%s: No need to turn tombstone %s to glue; it was already resurrected.\n",
 		                sessionid, addingdn);
 		op_result = LDAP_SUCCESS;

ldap/servers/slapd/add.c

@@ -732,9 +732,9 @@ static void op_shared_add (Slapi_PBlock *pb)
 		
 		if (be->be_add != NULL)
 		{
-			rc = (*be->be_add)(pb);
 			/* backend may change this if errors and not consumed */
 			slapi_pblock_get(pb, SLAPI_ADD_ENTRY, &save_e);
+			rc = (*be->be_add)(pb);
 			slapi_pblock_set(pb, SLAPI_ADD_ENTRY, ec);
 			if (rc == 0)
 			{

ldap/servers/slapd/attrlist.c

@@ -312,6 +312,13 @@ int attrlist_replace(Slapi_Attr **alist, const char *type, struct berval **vals)
             (*a)->a_flags |= SLAPI_ATTR_FLAG_NORMALIZED_CES;
         }
         rc = attr_replace(*a, values);
+        if (rc) {
+            slapi_log_error(SLAPI_LOG_FATAL, "attrlist_replace",
+                            "attr_replace (%s, %s) failed.\n",
+                            type, vals[0]->bv_val);
+            valuearray_free(&values);
+            slapi_attr_free(a);
+        }
     }
     return rc;
 }

ldap/servers/slapd/back-ldbm/cache.c

@@ -47,6 +47,7 @@
 #ifdef DEBUG
 #define LDAP_CACHE_DEBUG
 /* #define LDAP_CACHE_DEBUG_LRU * causes slowdown */
+/* #define CACHE_DEBUG * causes slowdown */
 #endif
 
 /* cache can't get any smaller than this (in bytes) */
@@ -1341,14 +1342,14 @@ entrycache_add_int(struct cache *cache, struct backentry *e, int state,
         {
             if (my_alt->ep_state & ENTRY_STATE_CREATING)
             {
-                LOG("the entry %s is reserved (ep_state: 0x%x, state: 0x%x\n", ndn, e->ep_state, state);
+                LOG("the entry %s is reserved (ep_state: 0x%x, state: 0x%x)\n", ndn, e->ep_state, state);
                 e->ep_state |= ENTRY_STATE_NOTINCACHE;
                 PR_Unlock(cache->c_mutex);
                 return -1;
             }
             else if (state != 0)
             {
-                LOG("the entry %s already exists. cannot reserve it. (ep_state: 0x%x, state: 0x%x\n",
+                LOG("the entry %s already exists. cannot reserve it. (ep_state: 0x%x, state: 0x%x)\n",
                     ndn, e->ep_state, state);
                 e->ep_state |= ENTRY_STATE_NOTINCACHE;
                 PR_Unlock(cache->c_mutex);
@@ -1519,20 +1520,20 @@ int cache_lock_entry(struct cache *cache, struct backentry *e)
     LOG("=> cache_lock_entry (%s)\n", backentry_get_ndn(e), 0, 0);
 
     if (! e->ep_mutexp) {
-       /* make sure only one thread does this */
-       PR_Lock(cache->c_emutexalloc_mutex);
-       if (! e->ep_mutexp) {
-           e->ep_mutexp = PR_NewMonitor();
-           if (!e->ep_mutexp) {
-               LOG("<= cache_lock_entry (DELETED)\n", 0, 0, 0);
-               LDAPDebug1Arg(LDAP_DEBUG_ANY,
-                             "cache_lock_entry: failed to create a lock for %s\n",
-                             backentry_get_ndn(e));
-               LOG("<= cache_lock_entry (FAILED)\n", 0, 0, 0);
-               return 1;
-           }
-       }
-       PR_Unlock(cache->c_emutexalloc_mutex);
+        /* make sure only one thread does this */
+        PR_Lock(cache->c_emutexalloc_mutex);
+        if (! e->ep_mutexp) {
+            e->ep_mutexp = PR_NewMonitor();
+            if (!e->ep_mutexp) {
+                LOG("<= cache_lock_entry (DELETED)\n", 0, 0, 0);
+                LDAPDebug1Arg(LDAP_DEBUG_ANY,
+                              "cache_lock_entry: failed to create a lock for %s\n",
+                              backentry_get_ndn(e));
+                LOG("<= cache_lock_entry (FAILED)\n", 0, 0, 0);
+                return 1;
+            }
+        }
+        PR_Unlock(cache->c_emutexalloc_mutex);
     }
 
     /* wait on entry lock (done w/o holding the cache lock) */
@@ -2018,3 +2019,61 @@ dn_lru_verify(struct cache *cache, struct backdn *dn, int in)
     ASSERT(is_in == in);
 }
 #endif
+
+#ifdef CACHE_DEBUG
+void
+check_entry_cache(struct cache *cache, struct backentry *e, int in_cache)
+{
+	Slapi_DN *sdn = slapi_entry_get_sdn(e->ep_entry);
+	struct backentry *debug_e = cache_find_dn(cache, 
+	                                          slapi_sdn_get_dn(sdn),
+	                                          slapi_sdn_get_ndn_len(sdn));
+	if (in_cache) {
+		if (debug_e) { /* e is in cache */
+			CACHE_RETURN(cache, &debug_e);
+			if ((e != debug_e) && !(e->ep_state & ENTRY_STATE_DELETED)) {
+				slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete",
+				                "entry 0x%p is not in dn cache but 0x%p having the same dn %s is "
+				                "although in_cache flag is set!!!\n",
+				                e, debug_e, slapi_sdn_get_dn(sdn));
+			}
+		} else if (!(e->ep_state & ENTRY_STATE_DELETED)) {
+			slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete",
+			                "%s (id %d) is not in dn cache although in_cache flag is set!!!\n",
+			                slapi_sdn_get_dn(sdn), e->ep_id);
+		}
+		debug_e = cache_find_id(cache, e->ep_id);
+		if (debug_e) { /* e is in cache */
+			CACHE_RETURN(cache, &debug_e);
+			if ((e != debug_e) && !(e->ep_state & ENTRY_STATE_DELETED)) {
+				slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete",
+				                "entry 0x%p is not in id cache but 0x%p having the same id %d is "
+				                "although in_cache flag is set!!!\n",
+				                e, debug_e, e->ep_id);
+			}
+		} else {
+			slapi_log_error(SLAPI_LOG_CACHE, "ldbm_back_delete",
+			                "%s (id %d) is not in id cache although in_cache flag is set!!!\n",
+			                slapi_sdn_get_dn(sdn), e->ep_id);
+		}
+	} else {
+		if (debug_e) { /* e is in cache */
+			CACHE_RETURN(cache, &debug_e);
+			if (e == debug_e) {
+				slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete",
+				                "%s (id %d) is in dn cache although in_cache flag is not set!!!\n",
+				                slapi_sdn_get_dn(sdn), e->ep_id);
+			}
+		}
+		debug_e = cache_find_id(cache, e->ep_id);
+		if (debug_e) { /* e is in cache: bad */
+			CACHE_RETURN(cache, &debug_e);
+			if (e == debug_e) {
+				slapi_log_error(SLAPI_LOG_CACHE, "ldbm_back_delete",
+				                "%s (id %d) is in id cache although in_cache flag is not set!!!\n",
+				                slapi_sdn_get_dn(sdn), e->ep_id);
+			}
+		}
+	}
+}
+#endif

ldap/servers/slapd/back-ldbm/ldbm_add.c

@@ -120,7 +120,13 @@ ldbm_back_add( Slapi_PBlock *pb )
 	int not_an_error = 0;
 	int parent_switched = 0;
 	int noabort = 1;
-
+	int myrc = 0;
+	PRUint64 conn_id;
+	int op_id;
+	if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
+		conn_id = 0; /* connection is NULL */
+	}
+	slapi_pblock_get(pb, SLAPI_OPERATION_ID, &op_id);
 	slapi_pblock_get( pb, SLAPI_PLUGIN_PRIVATE, &li );
 	slapi_pblock_get( pb, SLAPI_ADD_ENTRY, &e );
 	slapi_pblock_get( pb, SLAPI_REQUESTOR_ISROOT, &isroot );
@@ -813,6 +819,9 @@ ldbm_back_add( Slapi_PBlock *pb )
 				retval = parent_update_on_childchange(&parent_modify_c,
 				                                      is_resurect_operation?PARENTUPDATE_RESURECT:PARENTUPDATE_ADD,
 				                                      NULL);
+				slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_add",
+				                "conn=%lu op=%d parent_update_on_childchange: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+				                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, retval);
 				/* The modify context now contains info needed later */
 				if (retval) {
 					LDAPDebug2Args(LDAP_DEBUG_BACKLDBM, "parent_update_on_childchange: %s, rc=%d\n",
@@ -972,6 +981,9 @@ ldbm_back_add( Slapi_PBlock *pb )
 		if (parent_found) {
 			/* Push out the db modifications from the parent entry */
 			retval = modify_update_all(be,pb,&parent_modify_c,&txn);
+				slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_add",
+				                "conn=%lu op=%d modify_update_all: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+				                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, retval);
 			if (DB_LOCK_DEADLOCK == retval)
 			{
 				LDAPDebug( LDAP_DEBUG_ARGS, "add 6 DEADLOCK\n", 0, 0, 0 );
@@ -1100,8 +1112,13 @@ ldbm_back_add( Slapi_PBlock *pb )
 	if (parent_found)
 	{
 		/* switch the parent entry copy into play */
-		modify_switch_entries(&parent_modify_c,be);
-		parent_switched = 1;
+		myrc = modify_switch_entries(&parent_modify_c,be);
+		slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_add",
+		                "conn=%lu op=%d modify_switch_entries: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+		                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, myrc);
+		if (0 == myrc) {
+			parent_switched = 1;
+		}
 	}
 
 	if (ruv_c_init) {
@@ -1181,13 +1198,16 @@ error_return:
 	} else if (0 == rc) {
 		rc = SLAPI_FAIL_GENERAL;
 	}
-	if (parent_switched){
+	if (parent_switched) {
 		/*
 		 * Restore the old parent entry, switch the new with the original.
 		 * Otherwise the numsubordinate count will be off, and could later
 		 * be written to disk.
 		 */
-		modify_unswitch_entries( &parent_modify_c,be);
+		myrc = modify_unswitch_entries(&parent_modify_c, be);
+		slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_add",
+		                "conn=%lu op=%d modify_unswitch_entries: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+		                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, myrc);
 	}
 diskfull_return:
 	if (disk_full) {
@@ -1287,7 +1307,10 @@ common_return:
 	if (ruv_c_init) {
 		modify_term(&ruv_c, be);
 	}
-	modify_term(&parent_modify_c,be);
+	slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_add",
+	                "conn=%lu op=%d modify_term: old_entry=0x%p, new_entry=0x%p\n",
+	                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry);
+	myrc = modify_term(&parent_modify_c,be);
 	done_with_pblock_entry(pb,SLAPI_ADD_EXISTING_DN_ENTRY);
 	done_with_pblock_entry(pb,SLAPI_ADD_EXISTING_UNIQUEID_ENTRY);
 	done_with_pblock_entry(pb,SLAPI_ADD_PARENT_ENTRY);

ldap/servers/slapd/back-ldbm/ldbm_delete.c

@@ -99,6 +99,14 @@ ldbm_back_delete( Slapi_PBlock *pb )
 	int opreturn = 0;
 	int free_delete_existing_entry = 0;
 	int not_an_error = 0;
+	int parent_switched = 0;
+	int myrc = 0;
+	PRUint64 conn_id;
+	int op_id;
+	if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
+		conn_id = 0; /* connection is NULL */
+	}
+	slapi_pblock_get(pb, SLAPI_OPERATION_ID, &op_id);
 
 	slapi_pblock_get( pb, SLAPI_BACKEND, &be);
 	slapi_pblock_get( pb, SLAPI_PLUGIN_PRIVATE, &li );
@@ -292,8 +300,9 @@ ldbm_back_delete( Slapi_PBlock *pb )
 			retval = slapi_entry_has_children(e->ep_entry);
 			if (retval) {
 				ldap_result_code= LDAP_NOT_ALLOWED_ON_NONLEAF;
-				slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete", "Deleting entry %s has %d children.\n", 
-				                slapi_entry_get_dn(e->ep_entry), retval);
+				slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete", 
+				                "conn=%lu op=%d Deleting entry %s has %d children.\n", 
+				                conn_id, op_id, slapi_entry_get_dn(e->ep_entry), retval);
 				retval = -1;
 				goto error_return;
 			}
@@ -539,6 +548,10 @@ ldbm_back_delete( Slapi_PBlock *pb )
 						op |= PARENTUPDATE_DELETE_TOMBSTONE;
 					}
 					retval = parent_update_on_childchange(&parent_modify_c, op, &haschildren);
+					slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_delete",
+					                "conn=%lu op=%d parent_update_on_childchange: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+					                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, retval);
+
 					/* The modify context now contains info needed later */
 					if (0 != retval) {
 						ldap_result_code= LDAP_OPERATIONS_ERROR;
@@ -575,9 +588,11 @@ ldbm_back_delete( Slapi_PBlock *pb )
 				char *edn = slapi_entry_get_dn(e->ep_entry);
 				char *tombstone_dn;
 				Slapi_Value *tomb_value;
-		
+
 				if (slapi_is_special_rdn(edn, RDN_IS_TOMBSTONE)) {
-					LDAPDebug1Arg(LDAP_DEBUG_ANY, "Turning a tombstone into a tombstone! \"%s\"\n", edn);
+					slapi_log_error(SLAPI_LOG_FATAL, "ldbm_back_delete",
+					                "conn=%lu op=%d Turning a tombstone into a tombstone! \"%s\"; e: 0x%p, cache_state: 0x%x, refcnt: %d\n", 
+					                conn_id, op_id, edn, e, e->ep_state, e->ep_refcnt);
 					ldap_result_code= LDAP_OPERATIONS_ERROR;
 					retval = -1;
 					goto error_return;
@@ -708,9 +723,9 @@ ldbm_back_delete( Slapi_PBlock *pb )
 			if (0 == retval) {
 				tombstone_in_cache = 1;
 			} else {
-				LDAPDebug2Args(LDAP_DEBUG_ANY,
-				               "tombstone entry %s failed to add to the cache: %d\n",
-				               slapi_entry_get_dn(tombstone->ep_entry), retval);
+				slapi_log_error(SLAPI_LOG_CACHE, "ldbm_back_delete",
+				                "conn=%lu op=%d tombstone entry %s failed to add to the cache: %d\n",
+				                conn_id, op_id, slapi_entry_get_dn(tombstone->ep_entry), retval);
 				tombstone_in_cache = 0;
 				if (LDBM_OS_ERR_IS_DISKFULL(retval)) disk_full = 1;
 				DEL_SET_ERROR(ldap_result_code, 
@@ -1107,6 +1122,9 @@ ldbm_back_delete( Slapi_PBlock *pb )
 		if (parent_found) {
 			/* Push out the db modifications from the parent entry */
 			retval = modify_update_all(be,pb,&parent_modify_c,&txn);
+			slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_delete",
+			                "conn=%lu op=%d modify_update_all: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+			                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, retval);
 			if (DB_LOCK_DEADLOCK == retval)
 			{
 				LDAPDebug( LDAP_DEBUG_BACKLDBM, "del 4 DEADLOCK\n", 0, 0, 0 );
@@ -1256,7 +1274,13 @@ ldbm_back_delete( Slapi_PBlock *pb )
 	if (parent_found)
 	{
 		/* Replace the old parent entry with the newly modified one */
-		modify_switch_entries( &parent_modify_c,be);
+		myrc = modify_switch_entries( &parent_modify_c,be);
+		slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_delete",
+		                "conn=%lu op=%d modify_switch_entries: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+		                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, myrc);
+		if (myrc == 0) {
+			parent_switched = 1;
+		}
 	}
 
 	rc= 0;
@@ -1271,6 +1295,9 @@ error_return:
 				CACHE_RETURN(&inst->inst_dncache, &bdn);
 			} 
 		}
+#ifdef CACHE_DEBUG
+		check_entry_cache(&inst->inst_cache, tombstone, tombstone_in_cache);
+#endif
 		if (tombstone_in_cache) { /* successfully replaced */
 			CACHE_REMOVE( &inst->inst_cache, tombstone );
 			CACHE_RETURN( &inst->inst_cache, &tombstone );
@@ -1283,6 +1310,9 @@ error_return:
 
 	/* Need to return to cache after post op plugins are called */
 	if (e) {
+#ifdef CACHE_DEBUG
+		check_entry_cache(&inst->inst_cache, e, e_in_cache);
+#endif
 		if (e_in_cache) {
 			if (remove_e_from_cache) {
 				/* The entry is already transformed to a tombstone. */
@@ -1346,7 +1376,17 @@ error_return:
 		/* txn is no longer valid - reset the txn pointer to the parent */
 		slapi_pblock_set(pb, SLAPI_TXN, parent_txn);
 	}
-	
+	if (parent_switched) {
+		/*
+		 * Restore the old parent entry, switch the new with the original.
+		 * Otherwise the numsubordinate count will be off, and could later
+		 * be written to disk.
+		 */
+		myrc = modify_unswitch_entries(&parent_modify_c, be);
+		slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_delete",
+		                "conn=%lu op=%d modify_unswitch_entries: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+		                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, myrc);
+	}
 common_return:
 	if (orig_entry) {
 		/* NOTE: #define SLAPI_DELETE_BEPREOP_ENTRY SLAPI_ENTRY_PRE_OP */
@@ -1374,6 +1414,9 @@ common_return:
 				}
 			}
 		}
+#ifdef CACHE_DEBUG
+		check_entry_cache(&inst->inst_cache, tombstone, tombstone_in_cache);
+#endif
 		if (tombstone_in_cache) { /* successfully replaced */
 			CACHE_RETURN( &inst->inst_cache, &tombstone );
 			tombstone = NULL;
@@ -1408,7 +1451,10 @@ diskfull_return:
 		}
 		slapi_send_ldap_result( pb, ldap_result_code, NULL, ldap_result_message, 0, NULL );
 	}
-	modify_term(&parent_modify_c, be);
+	slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_delete",
+	                "conn=%lu op=%d modify_term: old_entry=0x%p, new_entry=0x%p, in_cache=%d\n",
+	                conn_id, op_id, parent_modify_c.old_entry, parent_modify_c.new_entry, parent_modify_c.new_entry_in_cache);
+	myrc = modify_term(&parent_modify_c, be);
 	if (rc == 0 && opcsn && !is_fixup_operation && !delete_tombstone_entry)
 	{
 		/* URP Naming Collision

ldap/servers/slapd/back-ldbm/ldbm_modify.c

@@ -140,7 +140,7 @@ modify_unswitch_entries(modify_context *mc,backend *be)
 	ldbm_instance *inst = (ldbm_instance *) be->be_instance_info;
 	int ret = 0;
 
-	if (mc->old_entry!=NULL && mc->new_entry!=NULL) {
+	if (mc->old_entry && mc->new_entry && mc->new_entry_in_cache) {
 		/* switch the entries, and reset the new, new, entry */
 		tmp_be = mc->new_entry;
 		mc->new_entry = mc->old_entry;

ldap/servers/slapd/back-ldbm/ldbm_modrdn.c

@@ -124,6 +124,13 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
     int free_modrdn_existing_entry = 0;
     int not_an_error = 0;
     int support_moddn_aci;
+    int myrc = 0;
+    PRUint64 conn_id;
+    int op_id;
+    if (slapi_pblock_get(pb, SLAPI_CONN_ID, &conn_id) < 0) {
+        conn_id = 0; /* connection is NULL */
+    }
+    slapi_pblock_get(pb, SLAPI_OPERATION_ID, &op_id);
 
     /* sdn & parentsdn need to be initialized before "goto *_return" */
     slapi_sdn_init(&dn_newdn);
@@ -269,6 +276,9 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
             slapi_sdn_free(&dn_newsuperiordn);
             slapi_pblock_set(pb, SLAPI_MODRDN_NEWSUPERIOR_SDN, orig_dn_newsuperiordn);
             orig_dn_newsuperiordn = slapi_sdn_dup(orig_dn_newsuperiordn);
+#ifdef CACHE_DEBUG
+            check_entry_cache(&inst->inst_cache, ec, ec_in_cache);
+#endif
             if (ec_in_cache) {
                 /* New entry 'ec' is in the entry cache.
                  * Remove it from the cache . */
@@ -780,7 +790,8 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
                     ldap_result_code= LDAP_ALREADY_EXISTS;
                     if (is_resurect_operation) {
                         slapi_log_error(SLAPI_LOG_CACHE, "ldbm_back_modrdn",
-                                        "cache_add_tentative failed: %s\n", slapi_entry_get_dn(ec->ep_entry));
+                                        "conn=%lu op=%d cache_add_tentative failed: %s\n", 
+                                        conn_id, op_id, slapi_entry_get_dn(ec->ep_entry));
                     }
                     goto error_return;
                 }
@@ -923,6 +934,10 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
                 if (parententry) {
                     retval = parent_update_on_childchange(&parent_modify_context,
                                                           PARENTUPDATE_DEL, NULL);
+                    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                                    "conn=%lu op=%d parent_update_on_childchange: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+                                    conn_id, op_id, parent_modify_context.old_entry, parent_modify_context.new_entry, retval);
+
                     /* The parent modify context now contains info needed later */
                     if (retval) {
                         goto error_return;
@@ -931,6 +946,9 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
                 if (newparententry) {
                     retval = parent_update_on_childchange(&newparent_modify_context,
                                                           PARENTUPDATE_ADD, NULL);
+                    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                                    "conn=%lu op=%d parent_update_on_childchange: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+                                    conn_id, op_id, parent_modify_context.old_entry, parent_modify_context.new_entry, retval);
                     /* The newparent modify context now contains info needed later */
                     if (retval) {
                         goto error_return;
@@ -941,9 +959,11 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
             if (is_resurect_operation && parententry) {
                 retval = parent_update_on_childchange(&parent_modify_context, PARENTUPDATE_RESURECT, NULL);
                 if (retval) {
-                    LDAPDebug(LDAP_DEBUG_BACKLDBM, "parent_update_on_childchange parent %s of %s failed, rc=%d\n",
-                              slapi_entry_get_dn_const(parent_modify_context.old_entry->ep_entry),
-                              slapi_entry_get_dn_const(ec->ep_entry), retval);
+                    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                                    "conn=%lu op=%d parent_update_on_childchange parent %s of %s failed, rc=%d\n",
+                                    conn_id, op_id,
+                                    slapi_entry_get_dn_const(parent_modify_context.old_entry->ep_entry),
+                                    slapi_entry_get_dn_const(ec->ep_entry), retval);
                     goto error_return;
                 }
             }
@@ -1129,6 +1149,9 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
             else /* retval == 0 */
             {
                 retval = modify_update_all(be, pb, &newparent_modify_context, &txn);
+                slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                                "conn=%lu op=%d modify_update_all: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+                                conn_id, op_id, parent_modify_context.old_entry, parent_modify_context.new_entry, retval);
                 if (DB_LOCK_DEADLOCK == retval)
                 {
                     /* Retry txn */
@@ -1256,7 +1279,10 @@ ldbm_back_modrdn( Slapi_PBlock *pb )
     }
     if(newparententry!=NULL)
     {
-        modify_switch_entries( &newparent_modify_context,be);
+        myrc = modify_switch_entries( &newparent_modify_context,be);
+        slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                        "conn=%lu op=%d modify_switch_entries: old_entry=0x%p, new_entry=0x%p, rc=%d\n",
+                        conn_id, op_id, parent_modify_context.old_entry, parent_modify_context.new_entry, myrc);
     }
 
     slapi_pblock_set( pb, SLAPI_ENTRY_POST_OP, postentry );
@@ -1479,6 +1505,9 @@ common_return:
         }
         /* remove the new entry from the cache if the op failed -
            otherwise, leave it in */
+#ifdef CACHE_DEBUG
+		check_entry_cache(&inst->inst_cache, ec, ec_in_cache);
+#endif
         if (ec_in_cache && ec && inst) {
             if (retval) {
                 CACHE_REMOVE( &inst->inst_cache, ec );
@@ -1500,7 +1529,7 @@ common_return:
         if (inst->inst_ref_count) {
             slapi_counter_decrement(inst->inst_ref_count);
         }
-	}
+    }
 
     moddn_unlock_and_return_entry(be,&e);
 
@@ -1529,8 +1558,16 @@ common_return:
     slapi_sdn_done(&dn_newdn);
     slapi_sdn_done(&dn_newrdn);
     slapi_sdn_done(&dn_parentdn);
-    modify_term(&parent_modify_context,be);
-    modify_term(&newparent_modify_context,be);
+    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                    "conn=%lu op=%d modify_term: old_entry=0x%p, new_entry=0x%p\n",
+                    conn_id, op_id, parent_modify_context.old_entry, parent_modify_context.new_entry);
+    myrc = modify_term(&parent_modify_context,be);
+    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                    "conn=%lu op=%d modify_term: rc=%d\n", conn_id, op_id, myrc);
+    slapi_log_error(SLAPI_LOG_BACKLDBM, "ldbm_back_modrdn",
+                    "conn=%lu op=%d modify_term: old_entry=0x%p, new_entry=0x%p\n",
+                    conn_id, op_id, newparent_modify_context.old_entry, newparent_modify_context.new_entry);
+    myrc = modify_term(&newparent_modify_context,be);
     if (free_modrdn_existing_entry) {
         done_with_pblock_entry(pb,SLAPI_MODRDN_EXISTING_ENTRY);
     } else { /* owned by original_entry */
@@ -1939,6 +1976,7 @@ modrdn_rename_entry_update_indexes(back_txn *ptxn, Slapi_PBlock *pb, struct ldbm
         retval= -1;
         goto error_return;
     }
+	*e_in_cache = 0;
     if (orig_ec_in_cache) {
         /* ec was already added to the cache via cache_add_tentative (to reserve its spot in the cache)
            and/or id2entry_add - so it already had one refcount - cache_replace adds another refcount -

ldap/servers/slapd/back-ldbm/proto-back-ldbm.h

@@ -88,6 +88,9 @@ int cache_add_tentative(struct cache *cache, struct backentry *e,
 int cache_lock_entry(struct cache *cache, struct backentry *e);
 void cache_unlock_entry(struct cache *cache, struct backentry *e);
 int cache_replace(struct cache *cache, void *oldptr, void *newptr);
+#ifdef CACHE_DEBUG
+void check_entry_cache(struct cache *cache, struct backentry *e, int in_cache);
+#endif
 
 Hashtable *new_hash(u_long size, u_long offset, HashFn hfn,
                HashTestFn tfn);

ldap/servers/slapd/dn.c

@@ -2481,6 +2481,12 @@ slapi_sdn_get_rdn(const Slapi_DN *sdn,Slapi_RDN *rdn)
 	slapi_rdn_set_dn(rdn, slapi_sdn_get_dn(sdn));
 }
 
+void
+slapi_sdn_get_rdn_ext(const Slapi_DN *sdn, Slapi_RDN *rdn, int is_tombstone)
+{
+	slapi_rdn_set_dn_ext(rdn, slapi_sdn_get_dn(sdn), is_tombstone);
+}
+
 Slapi_DN *
 slapi_sdn_dup(const Slapi_DN *sdn)
 {

ldap/servers/slapd/rdn.c

@@ -324,15 +324,29 @@ slapi_rdn_init_rdn(Slapi_RDN *rdn,const Slapi_RDN *fromrdn)
 	rdn->rdn= slapi_ch_strdup(fromrdn->rdn);
 }
 
+/*
+ * flags: 
+ * SLAPI_RDN_SET_DN_SKIP_UNIQUEID -- strip uniqueid, and set to rdn
+ * SLAPI_RDN_SET_DN_INCLUDE_UNIQUEID -- set <uniqueid,rdn> to rdn
+ */
 void
-slapi_rdn_set_dn_ext(Slapi_RDN *rdn,const char *dn, int skip_tombstone)
+slapi_rdn_set_dn_ext(Slapi_RDN *rdn,const char *dn, int flags)
 {
 	const char *mydn = dn;
 	slapi_rdn_done(rdn);
-	if (skip_tombstone && slapi_is_special_rdn(dn, RDN_IS_TOMBSTONE)) {
-		mydn = dn + slapi_uniqueIDRdnSize() + 1/*,*/;
+	if (flags && slapi_is_special_rdn(dn, RDN_IS_TOMBSTONE)) {
+		if (SLAPI_RDN_SET_DN_SKIP_UNIQUEID == flags) {
+			mydn = dn + slapi_uniqueIDRdnSize() + 1/*,*/;
+			slapi_rdn_init_dn(rdn, mydn);
+		} else if (SLAPI_RDN_SET_DN_INCLUDE_UNIQUEID == flags) {
+			Slapi_DN sdn = {0};
+			slapi_sdn_set_dn_byval(&sdn, dn);
+			_slapi_rdn_init_all_dn_ext(rdn, (const Slapi_DN *)&sdn, 1);
+			slapi_sdn_done(&sdn);
+		}
+	} else {
+		slapi_rdn_init_dn(rdn, mydn);
 	}
-	slapi_rdn_init_dn(rdn, mydn);
 }
 
 void

ldap/servers/slapd/slapi-plugin.h

@@ -3163,7 +3163,9 @@ void slapi_rdn_init_rdn(Slapi_RDN *rdn,const Slapi_RDN *fromrdn);
  * \see slapi_rdn_set_rdn()
  */
 void slapi_rdn_set_dn(Slapi_RDN *rdn,const char *dn);
-void slapi_rdn_set_dn_ext(Slapi_RDN *rdn,const char *dn, int skip_tombstone);
+#define SLAPI_RDN_SET_DN_SKIP_UNIQUEID 1
+#define SLAPI_RDN_SET_DN_INCLUDE_UNIQUEID 2
+void slapi_rdn_set_dn_ext(Slapi_RDN *rdn,const char *dn, int flags);
 Slapi_RDN *slapi_rdn_new_all_dn(const char *dn);
 int slapi_rdn_init_all_dn(Slapi_RDN *rdn, const char *dn);
 int slapi_rdn_init_all_sdn(Slapi_RDN *rdn, const Slapi_DN *sdn);