[389-ds-base] branch master updated (22a11d9 -> a406205)

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

firstyear pushed a change to branch master
in repository 389-ds-base.

from  22a11d9   Ticket 49460 - replica_write_ruv log a failure even when it succeeds
       new  a406205   Ticket 49444 - huaf in task.c during high load import

The 1 revisions listed above as "new" are entirely new to this
repository and will be described in separate emails.  The revisions
listed as "adds" were already present in the repository and have only
been added to this reference.

Summary of changes:
 dirsrvtests/tests/suites/import/regression_test.py | 43 +++++---------
 ldap/servers/slapd/task.c                          | 67 ++++++++++++----------
 2 files changed, 51 insertions(+), 59 deletions(-)

[389-ds-base] 01/01: Ticket 49444 - huaf in task.c during high load import

[git repository hosting]

This is an automated email from the git hooks/post-receive script.

firstyear pushed a commit to branch master
in repository 389-ds-base.

commit a406205595b2fed010d5fa2c029a25ebd8d5022b
Author: William Brown 
Date:   Fri Nov 10 10:29:55 2017 +1000

Ticket 49444 - huaf in task.c during high load import

Bug Description:  Due to incorrect locking in task.c, it was possible
    for task.c to heap-use-after-free on the task-log message causing
    corruption or crashing during import of ldif.

Fix Description:  Correct the locking to be after the mods are
    commited to prevent the realloc from freeing before mod completes.

https://pagure.io/389-ds-base/issue/49444

Author: wibrown

Review by: lkrispen (Thank you!)
---
 dirsrvtests/tests/suites/import/regression_test.py | 43 +++++---------
 ldap/servers/slapd/task.c                          | 67 ++++++++++++----------
 2 files changed, 51 insertions(+), 59 deletions(-)

diff --git a/dirsrvtests/tests/suites/import/regression_test.py b/dirsrvtests/tests/suites/import/regression_test.py
index ad51721..8d1debb 100644
--- a/dirsrvtests/tests/suites/import/regression_test.py
+++ b/dirsrvtests/tests/suites/import/regression_test.py
@@ -12,6 +12,8 @@ from lib389.utils import time, ldap, os, logging
 from lib389.topologies import topology_st as topo
 from lib389._constants import BACKEND_NAME, BACKEND_SUFFIX

+from lib389.dbgen import dbgen
+
 DEBUGGING = os.getenv("DEBUGGING", default=False)
 if DEBUGGING:
     logging.getLogger(__name__).setLevel(logging.DEBUG)
@@ -46,26 +48,19 @@ def test_del_suffix_import(topo):
     log.info('Create LDIF file and import it')
     ldif_dir = topo.standalone.get_ldif_dir()
     ldif_file = os.path.join(ldif_dir, 'suffix_del1.ldif')
-    try:
-        topo.standalone.buildLDIF(10, ldif_file, suffix=TEST_SUFFIX1)
-    except OSError as e:
-        log.fatal('Failed to create test ldif, {} - {}'.format(e.errno, e.strerror))
-        assert False
+
+    dbgen(topo.standalone, 10, ldif_file, TEST_SUFFIX1)

log.info('Stopping the server and running offline import')
-    topo.standalone.stop(timeout=10)
+    topo.standalone.stop()
     assert topo.standalone.ldif2db(TEST_BACKEND1, TEST_SUFFIX1, None, None, ldif_file)
-    topo.standalone.start(timeout=5)
+    topo.standalone.start()

log.info('Deleting suffix-{}'.format(TEST_SUFFIX2))
     backend.delete()

log.info('Adding the same database-{} after deleting it'.format(TEST_BACKEND1))
-    try:
-        backends.create(properties={BACKEND_SUFFIX: TEST_SUFFIX1, BACKEND_NAME: TEST_BACKEND1})
-    except ldap.LDAPError as e:
-        log.error('Failed to add backend-{}, error-{}'.format(TEST_SUFFIX1, e.message['desc']))
-        assert False
+    backends.create(properties={BACKEND_SUFFIX: TEST_SUFFIX1, BACKEND_NAME: TEST_BACKEND1})

def test_del_suffix_backend(topo):
@@ -89,30 +84,18 @@ def test_del_suffix_backend(topo):
     log.info('Create LDIF file and import it')
     ldif_dir = topo.standalone.get_ldif_dir()
     ldif_file = os.path.join(ldif_dir, 'suffix_del2.ldif')
-    try:
-        topo.standalone.buildLDIF(10, ldif_file, suffix=TEST_SUFFIX2)
-    except OSError as e:
-        log.fatal('Failed to create test ldif, {} - {}'.format(e.errno, e.strerror))
-        assert False
-
-    log.info('Running online import with importLDIF task')
-    try:
-        topo.standalone.tasks.importLDIF(suffix=TEST_SUFFIX2, input_file=ldif_file, args={TASK_WAIT: True})
-    except ValueError as e:
-        log.error('Import failed' + e.message('desc'))
-        raise
+
+    dbgen(topo.standalone, 10, ldif_file, TEST_SUFFIX2)
+
+    topo.standalone.tasks.importLDIF(suffix=TEST_SUFFIX2, input_file=ldif_file, args={TASK_WAIT: True})

log.info('Deleting suffix-{}'.format(TEST_SUFFIX2))
     backend.delete()

log.info('Adding the same database-{} after deleting it'.format(TEST_BACKEND2))
-    try:
-        backends.create(properties={BACKEND_SUFFIX: TEST_SUFFIX2, BACKEND_NAME: TEST_BACKEND2})
-    except ldap.LDAPError as e:
-        log.error('Failed to add backend-{}, error-{}'.format(TEST_SUFFIX1, e.message['desc']))
-        assert False
+    backends.create(properties={BACKEND_SUFFIX: TEST_SUFFIX2, BACKEND_NAME: TEST_BACKEND2})
     log.info('Checking if server can be restarted after re-adding the same database')
-    topo.standalone.restart(timeout=10)
+    topo.standalone.restart()
     assert not topo.standalone.detectDisorderlyShutdown()

diff --git a/ldap/servers/slapd/task.c b/ldap/servers/slapd/task.c
index 53a0af5..7aabf40 100644
--- a/ldap/servers/slapd/task.c
+++ b/ldap/servers/slapd/task.c
@@ -218,9 +218,8 @@ slapi_task_log_notice_ext(Slapi_Task *task, char *format, va_list ap)

PR_vsnprintf(buffer, LOG_BUFFER, format, ap);

-    if (task->task_log_lock) {
-        PR_Lock(task->task_log_lock);
-    }
+    PR_ASSERT(task->task_log_lock);
+    PR_Lock(task->task_log_lock);
     len = 2 + strlen(buffer) + (task->task_log ? strlen(task->task_log) : 0);
     if ((len > MAX_SCROLLBACK_BUFFER) && task->task_log) {
         size_t i;
@@ -249,9 +248,7 @@ slapi_task_log_notice_ext(Slapi_Task *task, char *format, va_list ap)
     if (task->task_log[0])
         strcat(task->task_log, "\n");
     strcat(task->task_log, buffer);
-    if (task->task_log_lock) {
-        PR_Unlock(task->task_log_lock);
-    }
+    PR_Unlock(task->task_log_lock);

slapi_task_status_changed(task);
 }
@@ -286,9 +283,8 @@ slapi_task_log_notice(Slapi_Task *task, char *format, ...)
     PR_vsnprintf(buffer, LOG_BUFFER, format, ap);
     va_end(ap);

-    if (task->task_log_lock) {
-        PR_Lock(task->task_log_lock);
-    }
+    PR_ASSERT(task->task_log_lock);
+    PR_Lock(task->task_log_lock);
     len = 2 + strlen(buffer) + (task->task_log ? strlen(task->task_log) : 0);
     if ((len > MAX_SCROLLBACK_BUFFER) && task->task_log) {
         size_t i;
@@ -314,12 +310,11 @@ slapi_task_log_notice(Slapi_Task *task, char *format, ...)
         }
     }

-    if (task->task_log[0])
+    if (task->task_log[0]) {
         strcat(task->task_log, "\n");
-    strcat(task->task_log, buffer);
-    if (task->task_log_lock) {
-        PR_Unlock(task->task_log_lock);
     }
+    strcat(task->task_log, buffer);
+    PR_Unlock(task->task_log_lock);

slapi_task_status_changed(task);
 }
@@ -339,13 +334,9 @@ slapi_task_status_changed(Slapi_Task *task)
         return;
     }

-    if (task->task_log_lock) {
-        PR_Lock(task->task_log_lock);
-    }
+    PR_ASSERT(task->task_log_lock);
+    PR_Lock(task->task_log_lock);
     NEXTMOD(TASK_LOG_NAME, task->task_log);
-    if (task->task_log_lock) {
-        PR_Unlock(task->task_log_lock);
-    }
     NEXTMOD(TASK_STATUS_NAME, task->task_status);
     sprintf(s1, "%d", task->task_exitcode);
     sprintf(s2, "%d", task->task_progress);
@@ -365,8 +356,11 @@ slapi_task_status_changed(Slapi_Task *task)
     mod[cur] = NULL;
     modify_internal_entry(task->task_dn, mod);

-    for (i = 0; i < cur; i++)
+    for (i = 0; i < cur; i++) {
         slapi_ch_free((void **)&modlist[i].mod_values);
+    }
+
+    PR_Unlock(task->task_log_lock);

/*
      * Removed (task->task_state == SLAPI_TASK_CANCELLED) from
@@ -590,11 +584,24 @@ new_task(const char *rawdn, void *plugin)

dn = slapi_create_dn_string("%s", rawdn);
     if (NULL == dn) {
-        slapi_log_err(SLAPI_LOG_ERR,
-                      "new_task", "Invalid task dn: %s\n", rawdn);
+        slapi_log_err(SLAPI_LOG_ERR, "new_task", "Invalid task dn: %s\n", rawdn);
         return NULL;
     }
     task = (Slapi_Task *)slapi_ch_calloc(1, sizeof(Slapi_Task));
+
+    task->task_log_lock = PR_NewLock();
+    PR_ASSERT(task->task_log_lock);
+
+    if (task->task_log_lock == NULL) {
+        /* Failed to allocate! Uh Oh! */
+        slapi_ch_free((void **)&task);
+        slapi_log_err(SLAPI_LOG_ERR, "new_task", "Unable to allocate task lock for: %s\n", rawdn);
+        return NULL;
+    }
+
+    /* Now take our lock to setup everything correctly. */
+    PR_Lock(task->task_log_lock);
+
     PR_Lock(global_task_lock);
     task->next = global_task_list;
     global_task_list = task;
@@ -612,7 +619,7 @@ new_task(const char *rawdn, void *plugin)
                                    LDAP_SCOPE_BASE, "(objectclass=*)", task_modify, (void *)task);
     slapi_config_register_callback(SLAPI_OPERATION_DELETE, DSE_FLAG_PREOP, dn,
                                    LDAP_SCOPE_BASE, "(objectclass=*)", task_deny, NULL);
-/* don't add entries under this one */
+    /* don't add entries under this one */
 #if 0
     /* don't know why, but this doesn't work.  it makes the current add
      * operation fail. :(
@@ -620,8 +627,8 @@ new_task(const char *rawdn, void *plugin)
     slapi_config_register_callback(SLAPI_OPERATION_ADD, DSE_FLAG_PREOP, dn,
                                    LDAP_SCOPE_SUBTREE, "(objectclass=*)", task_deny, NULL);
 #endif
-    /* To protect task_log to be realloced if it's in use */
-    task->task_log_lock = PR_NewLock();
+
+    PR_Unlock(task->task_log_lock);

return task;
 }
@@ -769,16 +776,18 @@ modify_internal_entry(char *dn, LDAPMod **mods)
 static void
 task_generic_destructor(Slapi_Task *task)
 {
+
+    PR_ASSERT(task->task_log_lock);
+    PR_Lock(task->task_log_lock);
     if (task->task_log) {
         slapi_ch_free((void **)&task->task_log);
     }
     if (task->task_status) {
         slapi_ch_free((void **)&task->task_status);
     }
-    if (task->task_log_lock) {
-        PR_DestroyLock(task->task_log_lock);
-        task->task_log_lock = NULL;
-    }
+    PR_Unlock(task->task_log_lock);
+    PR_DestroyLock(task->task_log_lock);
+    task->task_log_lock = NULL;
     task->task_log = task->task_status = NULL;
 }