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 firstyear@redhat.com 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; }