Ticket #336 - [abrt] 389-ds-base-1.2.10.4-2.fc16: index_range_read_ext: Process /usr/sbin/ns-slapd was killed by signal 11 (SIGSEGV)

https://fedorahosted.org/389/ticket/336
Resolves: Ticket #336
Bug Description: [abrt] 389-ds-base-1.2.10.4-2.fc16: index_range_read_ext: Process /usr/sbin/ns-slapd was killed by signal 11 (SIGSEGV)
Reviewed by: nhosoi (Thanks!)
Branch: master
Fix Description:
1) Entries can be deleted out from under a search operation.  The range read
code was not handling this situation correctly.  The code should notice that
the index query was empty, and continue to the next highest key in the range.
2) DB cursor c_close() functions can return DB_LOCK_DEADLOCK that must be
reported to the higher level operation functions.  If not, then subsequent
operations in the same transaction fail.  When a DB_LOCK_DEADLOCK is returned
by any DB update operation in the transaction, the transaction must be aborted
and a new transaction begun before any other transacted db operations can
occur.
Platforms tested: RHEL6 x86_64
Flag Day: no
Doc impact: no
BZ: 808770

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

@@ -333,8 +333,14 @@ IDList * idl_new_fetch(
 error:
     /* Close the cursor */
     if (NULL != cursor) {
-        if (0 != cursor->c_close(cursor)) {
-            ldbm_nasty(filename,3,ret);
+        int ret2 = cursor->c_close(cursor);
+        if (ret2) {
+            ldbm_nasty(filename,3,ret2);
+            if (!ret) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                ret = ret2;
+            }
         }
     }
     *flag_err = ret;
@@ -418,8 +424,9 @@ int idl_new_insert_key(
 error:
     /* Close the cursor */
     if (NULL != cursor) {
-        if (0 != cursor->c_close(cursor)) {
-            ldbm_nasty(filename,56,ret);
+        int ret2 = cursor->c_close(cursor);
+        if (ret2) {
+            ldbm_nasty(filename,56,ret2);
         }
     }
 #else
@@ -439,7 +446,7 @@ error:
             /* this is okay */
             ret = 0;
         } else {
-            ldbm_nasty(filename,50,ret);
+            ldbm_nasty(filename,60,ret);
         }
     }
 #endif
@@ -491,8 +498,14 @@ int idl_new_delete_key(
 error:
     /* Close the cursor */
     if (NULL != cursor) {
-        if (0 != cursor->c_close(cursor)) {
-            ldbm_nasty(filename,24,ret);
+        int ret2 = cursor->c_close(cursor);
+        if (ret2) {
+            ldbm_nasty(filename,24,ret2);
+            if (!ret) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                ret = ret2;
+            }
         }
     }
     return ret;
@@ -559,14 +572,17 @@ static int idl_new_store_allids(backend *be, DB *db, DBT *key, DB_TXN *txn)
 error:
     /* Close the cursor */
     if (NULL != cursor) {
-        if (0 != cursor->c_close(cursor)) {
-            ldbm_nasty(filename,33,ret);
+        int ret2 = cursor->c_close(cursor);
+        if (ret2) {
+            ldbm_nasty(filename,33,ret2);
         }
     }
     return ret;
+#ifdef KRAZY_K0DE
 	/* If this function is called in "no-allids" mode, then it's a bug */
 	ldbm_nasty(filename,63,0);
 	return -1;
+#endif
 }
 #endif
 
@@ -662,8 +678,14 @@ int idl_new_store_block(
 error:
     /* Close the cursor */
     if (NULL != cursor) {
-        if (0 != cursor->c_close(cursor)) {
-            ldbm_nasty(filename,49,ret);
+        int ret2 = cursor->c_close(cursor);
+        if (ret2) {
+            ldbm_nasty(filename,49,ret2);
+            if (!ret) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                ret = ret2;
+            }
         }
     }
     return ret;

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

@@ -1496,14 +1496,23 @@ index_range_read_ext(
         if(retry_count == IDL_FETCH_RETRY_COUNT) {
           ldbm_nasty("index_range_read retry count exceeded",1095,*err);
         }
-        tmp2 = idl_union( be, idl, tmp );
-        idl_free( idl );
-        idl_free( tmp );
-        idl = tmp2;
-        if (ALLIDS(idl)) {
-            LDAPDebug(LDAP_DEBUG_TRACE, "index_range_read hit an allids value\n",
-                      0, 0, 0);
-            break;
+        if (!idl) {
+            if (slapi_is_loglevel_set(LDAP_DEBUG_TRACE)) {
+                char encbuf[BUFSIZ];
+                LDAPDebug2Args(LDAP_DEBUG_TRACE,
+                               "index_range_read_ext: cur_key=%s(%li bytes) was deleted - skipping\n",
+                               encoded(&cur_key, encbuf), (long)cur_key.dsize);
+            }
+        } else {
+            tmp2 = idl_union( be, idl, tmp );
+            idl_free( idl );
+            idl_free( tmp );
+            idl = tmp2;
+            if (ALLIDS(idl)) {
+                LDAPDebug(LDAP_DEBUG_TRACE, "index_range_read hit an allids value\n",
+                          0, 0, 0);
+                break;
+            }
         }
         if (DBT_EQ (&cur_key, &upperkey)) { /* this is the last key */
             break;

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

@@ -727,6 +727,12 @@ ldbm_back_delete( Slapi_PBlock *pb )
 					retval = index_addordel_values_sv(be, LDBM_PARENTID_STR, 
 					                                  svals, NULL, e->ep_id, 
 					                                  BE_INDEX_ADD, &txn);
+					if (DB_LOCK_DEADLOCK == retval) {
+						LDAPDebug0Args( LDAP_DEBUG_ARGS,
+										"delete (updating " LDBM_PARENTID_STR ") DB_LOCK_DEADLOCK\n");
+						/* Retry txn */
+						continue;
+					}
 					if ( retval ) {
 						LDAPDebug( LDAP_DEBUG_TRACE, 
 								"delete (deleting %s) failed, err=%d %s\n",
@@ -738,18 +744,33 @@ ldbm_back_delete( Slapi_PBlock *pb )
 						goto error_return;
 					}
 				}
-				entryrdn_index_entry(be, e, BE_INDEX_DEL, &txn);
-				retval =
-				        entryrdn_index_entry(be, tombstone, BE_INDEX_ADD, &txn);
+				retval = entryrdn_index_entry(be, e, BE_INDEX_DEL, &txn);
+				if (DB_LOCK_DEADLOCK == retval) {
+					LDAPDebug0Args( LDAP_DEBUG_ARGS,
+								"delete (deleting entryrdn) DB_LOCK_DEADLOCK\n");
+					/* Retry txn */
+					continue;
+				}
+				if (0 != retval) {
+					LDAPDebug2Args( LDAP_DEBUG_TRACE, 
+								"delete (deleting entryrdn) failed, err=%d %s\n",
+								retval,
+								(msg = dblayer_strerror( retval )) ? msg : "" );
+					if (LDBM_OS_ERR_IS_DISKFULL(retval)) disk_full = 1;
+					DEL_SET_ERROR(ldap_result_code, 
+								  LDAP_OPERATIONS_ERROR, retry_count);
+					goto error_return;
+				}
+				retval = entryrdn_index_entry(be, tombstone, BE_INDEX_ADD, &txn);
 				if (DB_LOCK_DEADLOCK == retval) {
 					LDAPDebug0Args( LDAP_DEBUG_ARGS,
-								"delete (adding entryrdn) DB_LOCK_DEADLOCK\n");
+								"adding (adding tombstone entryrdn) DB_LOCK_DEADLOCK\n");
 					/* Retry txn */
 					continue;
 				}
 				if (0 != retval) {
 					LDAPDebug2Args( LDAP_DEBUG_TRACE, 
-								"delete (adding entryrdn) failed, err=%d %s\n",
+								"adding (adding tombstone entryrdn) failed, err=%d %s\n",
 								retval,
 								(msg = dblayer_strerror( retval )) ? msg : "" );
 					if (LDBM_OS_ERR_IS_DISKFULL(retval)) disk_full = 1;

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

@@ -280,9 +280,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
                   "entryrdn_index_entry: Failed to close cursor: %s(%d)\n",
-                  dblayer_strerror(rc), rc);
+                  dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     if (db) {
@@ -388,9 +394,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
-                            "entryrdn_index_read: Failed to close cursor: "
-                            "%s(%d)\n", dblayer_strerror(rc), rc);
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
+                  "entryrdn_index_read: Failed to close cursor: %s(%d)\n",
+                  dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     if (db) {
@@ -841,9 +853,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
                   "entryrdn_rename_subtree: Failed to close cursor: %s(%d)\n",
-                  dblayer_strerror(rc), rc);
+                  dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     if (db) {
@@ -983,9 +1001,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
                   "entryrdn_get_subordinates: Failed to close cursor: %s(%d)\n",
-                  dblayer_strerror(rc), rc);
+                  dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     if (db) {
@@ -1147,9 +1171,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
                   "entryrdn_lookup_dn: Failed to close cursor: %s(%d)\n",
                   dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     /* it is guaranteed that db is not NULL. */
@@ -1294,9 +1324,15 @@ bail:
     if (cursor) {
         int myrc = cursor->c_close(cursor);
         if (0 != myrc) {
-            slapi_log_error(SLAPI_LOG_FATAL, ENTRYRDN_TAG,
+            int loglevel = (myrc == DB_LOCK_DEADLOCK) ? SLAPI_LOG_TRACE : SLAPI_LOG_FATAL;
+            slapi_log_error(loglevel, ENTRYRDN_TAG,
                   "entryrdn_get_parent: Failed to close cursor: %s(%d)\n",
-                  dblayer_strerror(rc), rc);
+                  dblayer_strerror(myrc), myrc);
+            if (!rc) {
+                /* if cursor close returns DEADLOCK, we must bubble that up
+                   to the higher layers for retries */
+                rc = myrc;
+            }
         }
     }
     /* it is guaranteed that db is not NULL. */