From 1ccbfe23576ac78f81d85bcce246e4d72cfc4db8 Mon Sep 17 00:00:00 2001 From: Thierry Bordaz Date: Apr 18 2019 07:37:36 +0000 Subject: [PATCH 1/3] Bug 1694263: Fix thread private variable initialization Fix description: The initialization of the thread private variable was buggy. The private variable required an allocated struct (per thread). The struct is allocated on demand (during get/set) when the retrieved (PR_GetThreadPrivate) struct is NULL. Signed-off-by: Thierry Bordaz --- diff --git a/src/back-sch.c b/src/back-sch.c index 9313cd5..2d0bad0 100644 --- a/src/back-sch.c +++ b/src/back-sch.c @@ -2306,7 +2306,7 @@ backend_betxn_pre_write_cb(Slapi_PBlock *pb) static int backend_be_pre_write_cb(Slapi_PBlock *pb) { - int ret; + int ret = 0; int lock_status; int lock_count; struct plugin_state *state; @@ -2334,6 +2334,7 @@ backend_be_pre_write_cb(Slapi_PBlock *pb) { } if (lock_status == MAP_RWLOCK_FREE) { + /* This thread does not hold the map lock */ set_plugin_monitor_count(1); if (plugin_wrlock() == 0) { @@ -2389,12 +2390,12 @@ backend_be_pre_write_cb(Slapi_PBlock *pb) { static int backend_be_post_write_cb(Slapi_PBlock *pb) { - int ret; - int lock_status; - int lock_count; - struct plugin_state *state; + int ret = 0; + int lock_status; + int lock_count; + struct plugin_state *state; - slapi_pblock_get(pb, SLAPI_PLUGIN_PRIVATE, &state); + slapi_pblock_get(pb, SLAPI_PLUGIN_PRIVATE, &state); if (wrap_get_call_level() > 0) { return 0; @@ -2409,47 +2410,47 @@ backend_be_post_write_cb(Slapi_PBlock *pb) wrap_inc_call_level(); - lock_status = get_plugin_monitor_status(); - lock_count = get_plugin_monitor_count(); - if (lock_status == MAP_RWLOCK_UNINIT) { - return 0; - } + lock_status = get_plugin_monitor_status(); + lock_count = get_plugin_monitor_count(); + if (lock_status == MAP_RWLOCK_UNINIT) { + return 0; + } - if (lock_count == 1) { - set_plugin_monitor_status(MAP_RWLOCK_FREE); - if (plugin_unlock() == 0) { - ret = 0; - } else { - slapi_log_error(SLAPI_LOG_PLUGIN, state->plugin_desc->spd_id, - "backend_be_post_write_cb: unable to release write lock\n"); - ret = -1; - } -#if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "backend_be_post_write_cb: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", - 0); -#endif + if (lock_count == 1) { + set_plugin_monitor_status(MAP_RWLOCK_FREE); + if (plugin_unlock() == 0) { + ret = 0; + } else { + slapi_log_error(SLAPI_LOG_PLUGIN, state->plugin_desc->spd_id, + "backend_be_post_write_cb: unable to release write lock\n"); + ret = -1; } - if (lock_count >= 1) { - set_plugin_monitor_count(lock_count - 1); #if DEBUG_MAP_LOCK - if (lock_count > 1) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "backend_be_post_write_cb: (%p) keep %s : count=%d\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", - lock_count - 1); - } else { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "backend_be_post_write_cb: (%p) is now %s : count=%d\n", - PR_GetCurrentThread(), - "MAP_RWLOCK_FREE", - lock_count - 1); - } + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "backend_be_post_write_cb: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", + 0); #endif + } + if (lock_count >= 1) { + set_plugin_monitor_count(lock_count - 1); +#if DEBUG_MAP_LOCK + if (lock_count > 1) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "backend_be_post_write_cb: (%p) keep %s : count=%d\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", + lock_count - 1); + } else { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "backend_be_post_write_cb: (%p) is now %s : count=%d\n", + PR_GetCurrentThread(), + "MAP_RWLOCK_FREE", + lock_count - 1); } +#endif + } wrap_dec_call_level(); return ret; diff --git a/src/back-shr.c b/src/back-shr.c index a227b0a..920c135 100644 --- a/src/back-shr.c +++ b/src/back-shr.c @@ -37,6 +37,7 @@ #endif #include +#include #include "../yp/yp.h" #ifdef HAVE_TCPD_H @@ -2867,31 +2868,61 @@ backend_shr_internal_postop_init(Slapi_PBlock *pb, struct plugin_state *state) return 0; } -static unsigned int thread_dummy; +PRBool use_lock_status = PR_FALSE; static unsigned int thread_plugin_lock_status; -static int thread_plugin_lock_count; +PRBool use_lock_count = PR_FALSE; +static unsigned int thread_plugin_lock_count; +/* + * https://developer.mozilla.org/en-US/docs/Mozilla/Projects/NSPR/Reference/PR_NewThreadPrivateIndex + * It is called each time: + * - PR_SetThreadPrivate is call with a not NULL private value + * - on thread exit + */ +static void +lock_status_free(void *ptr) +{ + int *lock_status = ptr; + if (lock_status) { + slapi_ch_free((void **)&lock_status); + } +} +static void +lock_count_free(void *ptr) +{ + int *lock_count = ptr; + if (lock_count) { + slapi_ch_free((void **)&lock_count); + } +} void init_map_lock(void) { +#if DEBUG_MAP_LOCK /* The plugin lock is initialized as free */ slapi_log_error(SLAPI_LOG_FATAL, "init_plugin_lock", "thread_id = %p\n", PR_GetCurrentThread()); +#endif - PR_NewThreadPrivateIndex (&thread_dummy, NULL); - PR_NewThreadPrivateIndex(&thread_plugin_lock_status, NULL); - PR_NewThreadPrivateIndex(&thread_plugin_lock_count, NULL); + if (PR_NewThreadPrivateIndex(&thread_plugin_lock_status, lock_status_free) == PR_SUCCESS) { + use_lock_status = PR_TRUE; + } + if (PR_NewThreadPrivateIndex(&thread_plugin_lock_count, lock_count_free) == PR_SUCCESS) { + use_lock_count = PR_TRUE; + } +#if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "init_plugin_lock", "thread_plugin_lock_status = %d\n", thread_plugin_lock_status); slapi_log_error(SLAPI_LOG_FATAL, "init_map_lock", "thread_plugin_lock_count = %d\n", thread_plugin_lock_count); +#endif } int rw_monitor_enabled(void) { - if (thread_plugin_lock_status) + if (use_lock_status) return (int) MAP_MONITOR_ENABLED; else return (int) MAP_MONITOR_DISABLED; @@ -2902,13 +2933,27 @@ get_plugin_monitor_status(void) { int ret; - if (thread_plugin_lock_status) - ret = (int) PR_GetThreadPrivate(thread_plugin_lock_status); - else + if (use_lock_status) { + int *lock_status_p; + lock_status_p = (int *) PR_GetThreadPrivate(thread_plugin_lock_status); + if (lock_status_p == NULL) { + /* if it was not initialized then allocates a structure + * that will be private to that thread. + * Later when the structure is retrieved (PR_GetThreadPrivate), the + * content of the structure can be read/write without allocating + * this private structure PR_SetThreadPrivate. + * So this branch is processed one time per each thread + */ + lock_status_p = (int *) slapi_ch_calloc(1, sizeof (int)); + PR_SetThreadPrivate(thread_plugin_lock_status, (void *) lock_status_p); + *lock_status_p = MAP_RWLOCK_FREE; + } + ret = *lock_status_p; + } else ret = (int) MAP_RWLOCK_UNINIT; #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "get_plugin_monitor_status", - "lock_status = %d (%p)\n", ret, PR_GetCurrentThread()); + "(%s) lock_status = %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", ret, PR_GetCurrentThread()); #endif return ret; } @@ -2918,15 +2963,26 @@ set_plugin_monitor_status(int lock_status) { #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "set_plugin_monitor_status", - "lock_status = %d --> %d (%p)\n", get_plugin_monitor_status(), (int) lock_status, PR_GetCurrentThread()); + "(%s) lock_status = %d --> %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", get_plugin_monitor_status(), (int) lock_status, PR_GetCurrentThread()); #endif - if (thread_plugin_lock_status) - PR_SetThreadPrivate(thread_plugin_lock_status, (void *) lock_status); - else - PR_SetThreadPrivate(thread_plugin_lock_status, (void *) MAP_RWLOCK_UNINIT); - - + if (use_lock_status) { + int *lock_status_p; + + lock_status_p = (int *) PR_GetThreadPrivate(thread_plugin_lock_status); + if (lock_status_p == NULL) { + /* if it was not initialized then allocates a structure + * that will be private to that thread. + * Later when the structure is retrieved (PR_GetThreadPrivate), the + * content of the structure can be read/write without allocating + * this private structure PR_SetThreadPrivate. + * So this branch is processed one time per each thread + */ + lock_status_p = (int *) slapi_ch_calloc(1, sizeof (int)); + PR_SetThreadPrivate(thread_plugin_lock_status, (void *) lock_status_p); + } + *lock_status_p = lock_status; + } } int @@ -2934,13 +2990,27 @@ get_plugin_monitor_count(void) { int ret; - if (thread_plugin_lock_count) - ret = (int) PR_GetThreadPrivate(thread_plugin_lock_count); - else + if (use_lock_count) { + int *lock_count; + lock_count = (int *) PR_GetThreadPrivate(thread_plugin_lock_count); + if (lock_count == NULL) { + /* if it was not initialized then allocates a structure + * that will be private to that thread. + * Later when the structure is retrieved (PR_GetThreadPrivate), the + * content of the structure can be read/write without allocating + * this private structure PR_SetThreadPrivate. + * So this branch is processed one time per each thread + */ + lock_count = (int *) slapi_ch_calloc(1, sizeof (int)); + PR_SetThreadPrivate(thread_plugin_lock_count, (void *) lock_count); + *lock_count = 0; + } + ret = *lock_count; + } else ret = (int) MAP_RWLOCK_UNINIT; #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "get_plugin_monitor_count", - "lock_count = %d (%p)\n", ret, PR_GetCurrentThread()); + "(%s) lock_count = %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", ret, PR_GetCurrentThread()); #endif return ret; } @@ -2950,13 +3020,23 @@ set_plugin_monitor_count(int lock_count) { #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "set_plugin_monitor_count", - "lock_count = %d --> %d (%p)\n", get_plugin_monitor_count(), (int) lock_count, PR_GetCurrentThread()); + "(%s) lock_count = %d --> %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", get_plugin_monitor_count(), (int) lock_count, PR_GetCurrentThread()); #endif - - if (thread_plugin_lock_count) - PR_SetThreadPrivate(thread_plugin_lock_count, (void *) lock_count); - else - PR_SetThreadPrivate(thread_plugin_lock_count, (void *) MAP_RWLOCK_UNINIT); - - + if (use_lock_count) { + int *lock_count_p; + + lock_count_p = (int *) PR_GetThreadPrivate(thread_plugin_lock_count); + if (lock_count_p == NULL) { + /* if it was not initialized then allocates a structure + * that will be private to that thread. + * Later when the structure is retrieved (PR_GetThreadPrivate), the + * content of the structure can be read/write without allocating + * this private structure PR_SetThreadPrivate. + * So this branch is processed one time per each thread + */ + lock_count_p = (int *) slapi_ch_calloc(1, sizeof (int)); + PR_SetThreadPrivate(thread_plugin_lock_count, (void *) lock_count_p); + } + *lock_count_p = lock_count; + } } diff --git a/src/map.c b/src/map.c index db9e093..e953925 100644 --- a/src/map.c +++ b/src/map.c @@ -1248,7 +1248,7 @@ int map_rdlock(void) { int lock_status; - int lock_count; + int lock_count; int rc = 0; if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { @@ -1260,7 +1260,7 @@ map_rdlock(void) lock_status = get_plugin_monitor_status(); - lock_count = get_plugin_monitor_count(); + lock_count = get_plugin_monitor_count(); #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map_rdlock", @@ -1271,52 +1271,52 @@ map_rdlock(void) slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", "map rdlock: old way lock_status == MAP_RWLOCK_UNINIT\n"); return wrap_rwlock_rdlock(map_data.lock); - } + } - if (lock_status == MAP_RWLOCK_FREE) { - /* The plugin lock is free, acquire it */ + if (lock_status == MAP_RWLOCK_FREE) { + /* The plugin lock is free, acquire it */ #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: current lock_status == MAP_RWLOCK_FREE\n"); + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map rdlock: current lock_status == MAP_RWLOCK_FREE\n"); #endif - set_plugin_monitor_status(MAP_RLOCK_HELD); - set_plugin_monitor_count(1); + set_plugin_monitor_status(MAP_RLOCK_HELD); + set_plugin_monitor_count(1); #if DEBUG_MAP_LOCK - if (lock_count != 0) { - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) ALERT !!! count was %d -> 1\n", PR_GetCurrentThread(), lock_count); - } + if (lock_count != 0) { + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map rdlock: (%p) ALERT !!! count was %d -> 1\n", PR_GetCurrentThread(), lock_count); + } #endif - /* Acquire the slapi plugin in read */ - rc = plugin_rdlock(); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); - return rc; - } + /* Acquire the slapi plugin in read */ + rc = plugin_rdlock(); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); + return rc; + } #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); #endif - rc = wrap_rwlock_rdlock(map_data.lock); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "Fail to acquire map lock in read (%d)\n", rc); - plugin_unlock(); - return rc; - } - return 0; - } + rc = wrap_rwlock_rdlock(map_data.lock); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "Fail to acquire map lock in read (%d)\n", rc); + plugin_unlock(); + return rc; + } + return 0; + } #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) was already hold %s : count=%d > %d!!!\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD": "MAP_RLOCK_HELD", - lock_count, lock_count + 1); + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map rdlock: (%p) was already hold %s : count=%d > %d!!!\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : "MAP_RLOCK_HELD", + lock_count, lock_count + 1); #endif - set_plugin_monitor_count(lock_count + 1); + set_plugin_monitor_count(lock_count + 1); return 0; } @@ -1324,7 +1324,7 @@ int map_wrlock(void) { int lock_status; - int lock_count; + int lock_count; int rc = 0; if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { @@ -1335,7 +1335,7 @@ map_wrlock(void) } lock_status = get_plugin_monitor_status(); - lock_count = get_plugin_monitor_count(); + lock_count = get_plugin_monitor_count(); #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map wrlock", @@ -1356,65 +1356,65 @@ map_wrlock(void) "map wrlock: current lock_status == MAP_LOCK_FREE\n"); #endif - set_plugin_monitor_count(1); + set_plugin_monitor_count(1); #if DEBUG_MAP_LOCK - if (lock_count != 0) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) ALERT !!! count was %d --> 1\n", PR_GetCurrentThread(), lock_count); - } + if (lock_count != 0) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: (%p) ALERT !!! count was %d --> 1\n", PR_GetCurrentThread(), lock_count); + } #endif - /* Acquire the slapi plugin in write */ - rc = plugin_wrlock(); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map wrlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); - return rc; - } + /* Acquire the slapi plugin in write */ + rc = plugin_wrlock(); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "map wrlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); + return rc; + } #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); #endif - rc = wrap_rwlock_wrlock(map_data.lock); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : fail to write lock map lock (%d)\n", PR_GetCurrentThread(), rc); - plugin_unlock(); - goto common; - } - } else { - set_plugin_monitor_count(lock_count + 1); + rc = wrap_rwlock_wrlock(map_data.lock); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : fail to write lock map lock (%d)\n", PR_GetCurrentThread(), rc); + plugin_unlock(); + goto common; + } + } else { + set_plugin_monitor_count(lock_count + 1); #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) %s --> MAP_WLOCK_HELD : count=%d\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD": "MAP_RLOCK_HELD", - lock_count + 1); + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: (%p) %s --> MAP_WLOCK_HELD : count=%d\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : "MAP_RLOCK_HELD", + lock_count + 1); #endif - if (lock_status == MAP_RLOCK_HELD) { - /* lock is already acquired in read */ + if (lock_status == MAP_RLOCK_HELD) { + /* lock is already acquired in read */ #if DEBUG_MAP_LOCK - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: weird situation map lock is held in read and now required in write mode\n"); + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: weird situation map lock is held in read and now required in write mode\n"); #endif - /* First free the lock held in read */ - rc = plugin_unlock(); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: fail to unlock plugin lock (%d)\n", rc); - goto common; - } + /* First free the lock held in read */ + rc = plugin_unlock(); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: fail to unlock plugin lock (%d)\n", rc); + goto common; + } - /* Second acquire it in write */ - rc = plugin_wrlock(); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: fail to write lock plugin lock (%d)\n", rc); - goto common; - } + /* Second acquire it in write */ + rc = plugin_wrlock(); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map wrlock: fail to write lock plugin lock (%d)\n", rc); + goto common; } } + } common: set_plugin_monitor_status(MAP_WLOCK_HELD); @@ -1425,7 +1425,7 @@ int map_unlock(void) { int lock_status; - int lock_count; + int lock_count; int rc = 0; if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { @@ -1436,7 +1436,7 @@ map_unlock(void) } lock_status = get_plugin_monitor_status(); - lock_count = get_plugin_monitor_count(); + lock_count = get_plugin_monitor_count(); #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map_unlock", @@ -1448,48 +1448,48 @@ map_unlock(void) "map_unlock: old way lock_status == MAP_RWLOCK_UNINIT\n"); return wrap_rwlock_unlock(map_data.lock); - } + } - if (lock_count == 1) { - set_plugin_monitor_status(MAP_RWLOCK_FREE); - rc = plugin_unlock(); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map unlock: fail to unlock plugin lock (%d)\n", rc); - goto common; - } -#if DEBUG_MAP_LOCK + if (lock_count == 1) { + set_plugin_monitor_status(MAP_RWLOCK_FREE); + rc = plugin_unlock(); + if (rc) { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map_unlock: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", - 0); + "map unlock: fail to unlock plugin lock (%d)\n", rc); + goto common; + } +#if DEBUG_MAP_LOCK + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map_unlock: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", + 0); #endif - rc = wrap_rwlock_unlock(map_data.lock); - if (rc) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + rc = wrap_rwlock_unlock(map_data.lock); + if (rc) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "map_unlock: fail to unlock map lock (%d)\n", rc); - goto common; - } + goto common; } - if (lock_count >= 1) { - set_plugin_monitor_count(lock_count - 1); + } + if (lock_count >= 1) { + set_plugin_monitor_count(lock_count - 1); #if DEBUG_MAP_LOCK - if (lock_count > 1) { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map_unlock: (%p) keep %s : count=%d\n", - PR_GetCurrentThread(), - (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", - lock_count - 1); - } else { - slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map_unlock: (%p) is now %s : count=%d\n", - PR_GetCurrentThread(), - "MAP_RWLOCK_FREE", - lock_count - 1); - } -#endif + if (lock_count > 1) { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map_unlock: (%p) keep %s : count=%d\n", + PR_GetCurrentThread(), + (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", + lock_count - 1); + } else { + slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", + "map_unlock: (%p) is now %s : count=%d\n", + PR_GetCurrentThread(), + "MAP_RWLOCK_FREE", + lock_count - 1); } +#endif + } common: return rc; From 5e6953c1d4e776f5e084ea69a4f6e6b485362b3d Mon Sep 17 00:00:00 2001 From: Thierry Bordaz Date: Apr 18 2019 07:37:36 +0000 Subject: [PATCH 2/3] Bug 1694263: improve debug msg to match pstack threadId Description: A pstack is showing threadId that differs from the the thread pointer. To match logs with pstack better to display the threadId https://bugzilla.redhat.com/show_bug.cgi?id=1694263 Signed-off-by: Thierry Bordaz --- diff --git a/src/back-sch.c b/src/back-sch.c index 2d0bad0..4cacb28 100644 --- a/src/back-sch.c +++ b/src/back-sch.c @@ -2346,14 +2346,14 @@ backend_be_pre_write_cb(Slapi_PBlock *pb) { } #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "backend_be_pre_write_cb: (%p) MAP_RWLOCK_FREE -> MAP_WLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); + "backend_be_pre_write_cb: (%p) MAP_RWLOCK_FREE -> MAP_WLOCK_HELD : count=%d\n", (void *) PR_MyThreadId(), 1); #endif } else { set_plugin_monitor_count(lock_count + 1); #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "backend_be_pre_write_cb: (%p) %s --> MAP_WLOCK_HELD : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD": "MAP_RLOCK_HELD", lock_count + 1); #endif @@ -2428,7 +2428,7 @@ backend_be_post_write_cb(Slapi_PBlock *pb) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "backend_be_post_write_cb: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", 0); #endif @@ -2439,13 +2439,13 @@ backend_be_post_write_cb(Slapi_PBlock *pb) if (lock_count > 1) { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "backend_be_post_write_cb: (%p) keep %s : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", lock_count - 1); } else { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "backend_be_post_write_cb: (%p) is now %s : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), "MAP_RWLOCK_FREE", lock_count - 1); } diff --git a/src/back-shr.c b/src/back-shr.c index 920c135..2bfdf52 100644 --- a/src/back-shr.c +++ b/src/back-shr.c @@ -2868,6 +2868,13 @@ backend_shr_internal_postop_init(Slapi_PBlock *pb, struct plugin_state *state) return 0; } +static int +PR_MyThreadId(void) +{ + PRThread *thr = PR_GetCurrentThread(); + PRUint32 myself = PR_GetThreadID(thr); + return myself; +} PRBool use_lock_status = PR_FALSE; static unsigned int thread_plugin_lock_status; PRBool use_lock_count = PR_FALSE; @@ -2953,7 +2960,7 @@ get_plugin_monitor_status(void) ret = (int) MAP_RWLOCK_UNINIT; #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "get_plugin_monitor_status", - "(%s) lock_status = %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", ret, PR_GetCurrentThread()); + "(%s) lock_status = %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", ret, (void *) PR_MyThreadId()); #endif return ret; } @@ -2963,7 +2970,7 @@ set_plugin_monitor_status(int lock_status) { #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "set_plugin_monitor_status", - "(%s) lock_status = %d --> %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", get_plugin_monitor_status(), (int) lock_status, PR_GetCurrentThread()); + "(%s) lock_status = %d --> %d (%p)\n", use_lock_status ? "TRUE" : "FALSE", get_plugin_monitor_status(), (int) lock_status, (void *) PR_MyThreadId()); #endif if (use_lock_status) { @@ -3010,7 +3017,7 @@ get_plugin_monitor_count(void) ret = (int) MAP_RWLOCK_UNINIT; #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "get_plugin_monitor_count", - "(%s) lock_count = %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", ret, PR_GetCurrentThread()); + "(%s) lock_count = %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", ret, (void *) PR_MyThreadId()); #endif return ret; } @@ -3020,7 +3027,7 @@ set_plugin_monitor_count(int lock_count) { #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "set_plugin_monitor_count", - "(%s) lock_count = %d --> %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", get_plugin_monitor_count(), (int) lock_count, PR_GetCurrentThread()); + "(%s) lock_count = %d --> %d (%p)\n", use_lock_count ? "TRUE" : "FALSE", get_plugin_monitor_count(), (int) lock_count, (void *) PR_MyThreadId()); #endif if (use_lock_count) { int *lock_count_p; diff --git a/src/back-shr.h b/src/back-shr.h index 8c68b4f..5d72ad9 100644 --- a/src/back-shr.h +++ b/src/back-shr.h @@ -30,6 +30,7 @@ #define MAP_WLOCK_HELD 2 #define MAP_RLOCK_HELD 1 #define MAP_RWLOCK_FREE 0 +static int PR_MyThreadId(void); int rw_monitor_enabled(void); int get_plugin_monitor_status(void); void set_plugin_monitor_status(int lock_status); diff --git a/src/map.c b/src/map.c index e953925..f80f465 100644 --- a/src/map.c +++ b/src/map.c @@ -1264,7 +1264,7 @@ map_rdlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map_rdlock", - "thread_id = %p (call level = %d)\n", PR_GetCurrentThread(), wrap_get_call_level()); + "thread_id = %p (call level = %d)\n", (void *) PR_MyThreadId(), wrap_get_call_level()); #endif if (lock_status == MAP_RWLOCK_UNINIT) { /* This is not initialized used the old way */ @@ -1284,7 +1284,7 @@ map_rdlock(void) #if DEBUG_MAP_LOCK if (lock_count != 0) { slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) ALERT !!! count was %d -> 1\n", PR_GetCurrentThread(), lock_count); + "map rdlock: (%p) ALERT !!! count was %d -> 1\n", (void *) PR_MyThreadId(), lock_count); } #endif @@ -1292,12 +1292,12 @@ map_rdlock(void) rc = plugin_rdlock(); if (rc) { slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); + "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", (void *) PR_MyThreadId(), rc); return rc; } #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); + "map rdlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD : count=%d\n", (void *) PR_MyThreadId(), 1); #endif rc = wrap_rwlock_rdlock(map_data.lock); if (rc) { @@ -1312,7 +1312,7 @@ map_rdlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", "map rdlock: (%p) was already hold %s : count=%d > %d!!!\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : "MAP_RLOCK_HELD", lock_count, lock_count + 1); #endif @@ -1339,7 +1339,7 @@ map_wrlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map wrlock", - "thread_id = %p (call level = %d)\n", PR_GetCurrentThread(), wrap_get_call_level()); + "thread_id = %p (call level = %d)\n", (void *) PR_MyThreadId(), wrap_get_call_level()); #endif if (lock_status == MAP_RWLOCK_UNINIT) { /* This is not initialized used the old way */ @@ -1360,25 +1360,25 @@ map_wrlock(void) #if DEBUG_MAP_LOCK if (lock_count != 0) { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) ALERT !!! count was %d --> 1\n", PR_GetCurrentThread(), lock_count); + "map wrlock: (%p) ALERT !!! count was %d --> 1\n", (void *) PR_MyThreadId(), lock_count); } #endif /* Acquire the slapi plugin in write */ rc = plugin_wrlock(); if (rc) { slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", - "map wrlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", PR_GetCurrentThread(), rc); + "map wrlock: (%p) MAP_RWLOCK_FREE -> MAP_RLOCK_HELD: fail to read lock plugin lock (%d)\n", (void *) PR_MyThreadId(), rc); return rc; } #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : count=%d\n", PR_GetCurrentThread(), 1); + "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : count=%d\n", (void *) PR_MyThreadId(), 1); #endif rc = wrap_rwlock_wrlock(map_data.lock); if (rc) { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", - "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : fail to write lock map lock (%d)\n", PR_GetCurrentThread(), rc); + "map wrlock: (%p) MAP_RWLOCK_FREE --> MAP_WLOCK_HELD : fail to write lock map lock (%d)\n", (void *) PR_MyThreadId(), rc); plugin_unlock(); goto common; } @@ -1387,7 +1387,7 @@ map_wrlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "map wrlock: (%p) %s --> MAP_WLOCK_HELD : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : "MAP_RLOCK_HELD", lock_count + 1); #endif @@ -1440,7 +1440,7 @@ map_unlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "map_unlock", - "thread_id = %p (call level = %d)\n", PR_GetCurrentThread(), wrap_get_call_level()); + "thread_id = %p (call level = %d)\n", (void *) PR_MyThreadId(), wrap_get_call_level()); #endif if (lock_status == MAP_RWLOCK_UNINIT) { /* This is not initialized used the old way */ @@ -1461,7 +1461,7 @@ map_unlock(void) #if DEBUG_MAP_LOCK slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "map_unlock: (%p) %s --> MAP_RWLOCK_FREE : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", 0); #endif @@ -1478,13 +1478,13 @@ map_unlock(void) if (lock_count > 1) { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "map_unlock: (%p) keep %s : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), (lock_status == MAP_WLOCK_HELD) ? "MAP_WLOCK_HELD" : (lock_status == MAP_RLOCK_HELD) ? "MAP_RLOCK_HELD" : "MAP_RWLOCK_FREE", lock_count - 1); } else { slapi_log_error(SLAPI_LOG_FATAL, "schema-compat", "map_unlock: (%p) is now %s : count=%d\n", - PR_GetCurrentThread(), + (void *) PR_MyThreadId(), "MAP_RWLOCK_FREE", lock_count - 1); } From 52fd1595699ea9859c2f4c41ae7ff425d65ae3cf Mon Sep 17 00:00:00 2001 From: Thierry Bordaz Date: Apr 18 2019 07:37:36 +0000 Subject: [PATCH 3/3] Bug 1694263: On some 'cn=config' updates bepost_op are not called that leads to lock leak Description: The true cause of the hang was that some updates on 'cn=config' can skip the BEPOST phase. (in this bug it was the maxbersize setting). The consequence is that the slapi-nis map lock was acquired but not released. The fix consist to ignore (not lock slapi-nis map) write operation done on 'cn=config' and 'cn=schema' https://bugzilla.redhat.com/show_bug.cgi?id=1694263 Signed-off-by: Thierry Bordaz --- diff --git a/src/back-sch.c b/src/back-sch.c index 4cacb28..9201c2e 100644 --- a/src/back-sch.c +++ b/src/back-sch.c @@ -2303,6 +2303,33 @@ backend_betxn_pre_write_cb(Slapi_PBlock *pb) slapi_pblock_get(pb, SLAPI_PLUGIN_PRIVATE, &state); return state->use_be_txns ? backend_write_cb(pb, state) : 0; } +static PRBool +backend_be_write_ignore(Slapi_PBlock *pb) +{ + char *dn = NULL; + Slapi_DN *target_sdn = NULL; + int check; + int i = 0; + PRBool ignore = PR_FALSE; + + /* Check if the target DN is a subordinates of + * on of the ignored containers + */ + slapi_pblock_get(pb, SLAPI_ORIGINAL_TARGET, &dn); + target_sdn = slapi_sdn_new_dn_byval(dn); + + for (i = 0; ignored_containers_sdn[i]; i++) { + check = slapi_sdn_issuffix(target_sdn, ignored_containers_sdn[i]); + if (check != 0) { + /* This entry is an ignored container */ + ignore = PR_TRUE; + break; + } + } + slapi_sdn_free(&target_sdn); + return ignore; +} + static int backend_be_pre_write_cb(Slapi_PBlock *pb) { @@ -2323,6 +2350,14 @@ backend_be_pre_write_cb(Slapi_PBlock *pb) { if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { return 0; } + if (backend_be_write_ignore(pb)) { +#if DEBUG_MAP_LOCK + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "backend_be_pre_write_cb: (%p) operation is not impacting schema compat\n", PR_MyThreadId(), 1); +#endif + return 0; + } + wrap_inc_call_level(); @@ -2404,9 +2439,16 @@ backend_be_post_write_cb(Slapi_PBlock *pb) /* No data to serve yet */ return 0; } - if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { - return 0; - } + if (rw_monitor_enabled() == MAP_MONITOR_DISABLED) { + return 0; + } + if (backend_be_write_ignore(pb)) { +#if DEBUG_MAP_LOCK + slapi_log_error(SLAPI_LOG_FATAL, "schemacompat", + "backend_be_post_write_cb: (%p) operation was not impacting schema compat\n", PR_MyThreadId(), 1); +#endif + return 0; + } wrap_inc_call_level(); diff --git a/src/back-shr.c b/src/back-shr.c index 2bfdf52..b348869 100644 --- a/src/back-shr.c +++ b/src/back-shr.c @@ -2868,7 +2868,7 @@ backend_shr_internal_postop_init(Slapi_PBlock *pb, struct plugin_state *state) return 0; } -static int +int PR_MyThreadId(void) { PRThread *thr = PR_GetCurrentThread(); @@ -2902,14 +2902,32 @@ lock_count_free(void *ptr) } } +/* This is used to ignore some write operations + * if they target subordinates entry of ignored containers + */ +Slapi_DN **ignored_containers_sdn = NULL; void init_map_lock(void) { #if DEBUG_MAP_LOCK /* The plugin lock is initialized as free */ slapi_log_error(SLAPI_LOG_FATAL, "init_plugin_lock", - "thread_id = %p\n", PR_GetCurrentThread()); + "thread_id = %p\n", PR_MyThreadId()); #endif + if (ignored_containers_sdn == NULL) { + /* allocates ignored_containers_sdn of Slapi_DN* only once + * It will be used later in be_pre/post_write_cb + */ + int cnt; + char *ignored_containers[3] = { "cn=config", "cn=schema", NULL}; + + for (cnt = 0; ignored_containers[cnt]; cnt++); + ignored_containers_sdn = (Slapi_DN **) slapi_ch_calloc(cnt + 1, sizeof(Slapi_DN *)); + + for (cnt = 0; ignored_containers[cnt]; cnt++) { + ignored_containers_sdn[cnt] = slapi_sdn_new_dn_byval(ignored_containers[cnt]); + } + } if (PR_NewThreadPrivateIndex(&thread_plugin_lock_status, lock_status_free) == PR_SUCCESS) { use_lock_status = PR_TRUE; diff --git a/src/back-shr.h b/src/back-shr.h index 5d72ad9..d01b999 100644 --- a/src/back-shr.h +++ b/src/back-shr.h @@ -30,13 +30,14 @@ #define MAP_WLOCK_HELD 2 #define MAP_RLOCK_HELD 1 #define MAP_RWLOCK_FREE 0 -static int PR_MyThreadId(void); +int PR_MyThreadId(void); int rw_monitor_enabled(void); int get_plugin_monitor_status(void); void set_plugin_monitor_status(int lock_status); int get_plugin_monitor_count(void); void set_plugin_monitor_count(int lock_count); void init_map_lock(void); +Slapi_DN **ignored_containers_sdn; struct plugin_state; diff --git a/src/plug-sch.c b/src/plug-sch.c index 2d9c75b..913abe2 100644 --- a/src/plug-sch.c +++ b/src/plug-sch.c @@ -197,6 +197,13 @@ plugin_shutdown(Slapi_PBlock *pb) if (state->plugin_base != NULL) { slapi_ch_free((void **)&state->plugin_base); } + if (ignored_containers_sdn) { + int i; + for (i = 0; ignored_containers_sdn[i]; i++) { + slapi_sdn_free(&ignored_containers_sdn[i]); + } + slapi_ch_free((void **)&ignored_containers_sdn); + } slapi_log_error(SLAPI_LOG_PLUGIN, state->plugin_desc->spd_id, "plugin shutdown completed\n"); return 0;