PR#49942: Ticket 49887: Clean thread local usage - 389-ds-base

389-ds-base

#49942 Ticket 49887: Clean thread local usage

Closed 3 years ago by spichugi. Opened 5 years ago by firstyear.

firstyear/389-ds-base 49941-clean-thread-local into master

Ticket 49887: Clean thread local usage

William Brown • 5 years ago

e59b309

ldap/servers/slapd/connection.c

file modified

-8

		`@@ -1514,8 +1514,6 @@`
		`SIGNAL(SIGPIPE, SIG_IGN);`
		`#endif`

		`- slapi_td_init_internal_logging();`
		`-`
		`while (1) {`
		`int is_timedout = 0;`
		`time_t curtime = 0;`
		`@@ -1525,7 +1523,6 @@`
		`"op_thread received shutdown signal\n");`
		`slapi_pblock_destroy(pb);`
		`g_decr_active_threadcnt();`
		`- slapi_td_free_internal_logging();`
		`return;`
		`}`

		`@@ -1547,7 +1544,6 @@`
		`"op_thread received shutdown signal\n");`
		`slapi_pblock_destroy(pb);`
		`g_decr_active_threadcnt();`
		`- slapi_td_free_internal_logging();`
		`return;`
		`case CONN_FOUND_WORK_TO_DO:`
		`/* note - don't need to lock here - connection should only`
		`@@ -1560,7 +1556,6 @@`
		`slapi_log_err(SLAPI_LOG_ERR, "connection_threadmain", "pb_conn is NULL\n");`
		`slapi_pblock_destroy(pb);`
		`g_decr_active_threadcnt();`
		`- slapi_td_free_internal_logging();`
		`return;`
		`}`

		`@@ -1627,7 +1622,6 @@`
		`slapi_log_err(SLAPI_LOG_ERR, "connection_threadmain", "NULL param: conn (0x%p) op (0x%p)\n", conn, op);`
		`slapi_pblock_destroy(pb);`
		`g_decr_active_threadcnt();`
		`- slapi_td_free_internal_logging();`
		`return;`
		`}`
		`maxthreads = config_get_maxthreadsperconn();`
		`@@ -1806,7 +1800,6 @@`
		`PR_ExitMonitor(conn->c_mutex);`
		`signal_listner();`
		`slapi_pblock_destroy(pb);`
		`- slapi_td_free_internal_logging();`
		`return;`
		`}`
		`/*`
		`@@ -1896,7 +1889,6 @@`
		`PR_ExitMonitor(conn->c_mutex);`
		`}`
		`} /* while (1) */`
		`- slapi_td_free_internal_logging();`
		`}`

		`/* thread need to hold conn->c_mutex before calling this function */`

ldap/servers/slapd/main.c

file modified

+11 -5

		`@@ -925,6 +925,17 @@`
		`}`

		`/*`
		`+ * init the thread data indexes. Nothing should be creating their`
		`+ * own thread data, and should be using this function instead`
		`+ * as we may swap to context based storage in the future rather`
		`+ * than direct thread-local accesses (especially important with`
		`+ * consideration of rust etc)`
		`+ *`
		`+ * DOES THIS NEED TO BE BEFORE OR AFTER NS?`
		`+ */`
		`+ slapi_td_init();`
		`+`
		`+ /*`
		`* Create our thread pool here for tasks to utilise.`
		`*/`
		`main_create_ns(&tp);`
		`@@ -1112,10 +1123,6 @@`
		`*/`
		`task_cleanup();`

		`- /* init the thread data indexes - need to initialize internal logging TD here for bootstrap startup */`
		`- slapi_td_init();`
		`- slapi_td_init_internal_logging();`
		`-`
		`/*`
		`* Initialize password storage in entry extension.`
		`* Need to be initialized before plugin_startall in case stucked`
		`@@ -1194,7 +1201,6 @@`
		`vattr_cleanup();`
		`sasl_map_done();`
		`cleanup:`
		`- slapi_td_free_internal_logging();`
		`compute_terminate();`
		`SSL_ShutdownServerSessionIDCache();`
		`SSL_ClearSessionCache();`

ldap/servers/slapd/slapi-private.h

file modified

+17 -12

		`@@ -1172,30 +1172,35 @@`
		`char *slapd_get_tmp_dir(void);`

		`/* thread-data.c */`
		`+ /* defines for internal logging */`
		`+ typedef enum _slapi_op_nest_state {`
		`+ OP_STATE_NOTNESTED = 0,`
		`+ OP_STATE_NESTED = 1,`
		`+ OP_STATE_UNNESTED = 2,`
		`+ } slapi_log_nest_state;`
		`+`
		`+`
		`+ struct slapi_td_log_op_state_t {`
		`+ int32_t op_id;`
		`+ int32_t op_int_id;`
		`+ int32_t op_nest_count;`
		`+ slapi_log_nest_state op_nest_state;`
		`+ int64_t conn_id;`
		`+ };`
		`+`
		`int slapi_td_init(void);`
		`- int slapi_td_set_val(int indexType, void *value);`
		`- void slapi_td_get_val(int indexType, void **value);`
		`- int slapi_td_dn_init(void);`
		`int slapi_td_set_dn(char *dn);`
		`void slapi_td_get_dn(char **dn);`
		`int slapi_td_plugin_lock_init(void);`
		`int slapi_td_get_plugin_locked(void);`
		`int slapi_td_set_plugin_locked(void);`
		`int slapi_td_set_plugin_unlocked(void);`
		`+ struct slapi_td_log_op_state_t * slapi_td_get_log_op_state(void);`
		`void slapi_td_internal_op_start(void);`
		`void slapi_td_internal_op_finish(void);`
		`- void slapi_td_init_internal_logging(void);`
		`void slapi_td_reset_internal_logging(uint64_t conn_id, int32_t op_id);`
		`- void slapi_td_free_internal_logging(void);`

		`/* Thread Local Storage Index Types - thread_data.c */`
		`- #define SLAPI_TD_REQUESTOR_DN 1`
		`- #define SLAPI_TD_PLUGIN_LIST_LOCK 2`
		`- #define SLAPI_TD_CONN_ID 3`
		`- #define SLAPI_TD_OP_ID 4`
		`- #define SLAPI_TD_OP_INTERNAL_ID 5`
		`- #define SLAPI_TD_OP_NESTED_COUNT 6`
		`- #define SLAPI_TD_OP_NESTED_STATE 7`

		`/* util.c */`
		`#include <stdio.h> /* GGOODREPL - For BUFSIZ, below, gak */`

ldap/servers/slapd/thread_data.c

file modified

+91 -316

		`@@ -10,276 +10,95 @@`
		`* Thread Local Storage Functions`
		`*/`
		`#include "slap.h"`
		`- #include <prthread.h>`
		`-`
		`- void td_dn_destructor(void *priv);`
		`+ #include <pthread.h>`

		`/*`
		`* Thread Local Storage Indexes`
		`*/`
		`- static PRUintn td_requestor_dn; /* TD_REQUESTOR_DN */`
		`- static PRUintn td_plugin_list; /* SLAPI_TD_PLUGIN_LIST_LOCK - integer set to 1 or zero */`
		`- static PRUintn td_conn_id;`
		`- static PRUintn td_op_id;`
		`- static PRUintn td_op_internal_id;`
		`- static PRUintn td_op_internal_nested_state;`
		`- static PRUintn td_op_internal_nested_count;`
		`-`
		`- /* defines for internal logging */`
		`- #define NOTNESTED 0`
		`- #define NESTED 1`
		`- #define UNNESTED 2`
		`+ static pthread_key_t td_requestor_dn; /* TD_REQUESTOR_DN */`
		`+ static pthread_key_t td_plugin_list; /* SLAPI_TD_PLUGIN_LIST_LOCK - integer set to 1 or zero */`
		`+ static pthread_key_t td_op_state;`

		`/*`
		`- * Index types defined in slapi-plugin.h`
		`- *`
		`- * #define SLAPI_TD_REQUESTOR_DN 1`
		`- * ...`
		`- * ...`
		`+ * Destructor Functions`
		`*/`

		`+ static void`
		`+ td_dn_destructor(void *priv)`
		`+ {`
		`+ slapi_ch_free((void **)&priv);`
		`+ }`

		`- /*`
		`- * The Process:`
		`- *`
		`- * [1] Create new index type macro in slapi-plugin.h`
		`- * [2] Create new static "PRUintn" index`
		`- * [3] Update these functions with the new index:`
		`- * slapi_td_init()`
		`- * slapi_td_set_val()`
		`- * slapi_td_get_val()`
		`- * [4] Create wrapper functions if so desired, and update slapi_plugin.h`
		`- * [5] Create destructor (if necessary)`
		`- */`
		`+ static void`
		`+ td_op_state_destroy(void *priv) {`
		`+ slapi_ch_free((void **)&priv);`
		`+ }`

		`- int`
		`+ int32_t`
		`slapi_td_init(void)`
		`{`
		`- if (PR_NewThreadPrivateIndex(&td_requestor_dn, td_dn_destructor) == PR_FAILURE) {`
		`+ if (pthread_key_create(&td_requestor_dn, td_dn_destructor) != 0) {`
		`slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_requestor_dn/td_dn_destructor\n");`
		`return PR_FAILURE;`
		`}`

		`- if (PR_NewThreadPrivateIndex(&td_plugin_list, NULL) == PR_FAILURE) {`
		`+ if (pthread_key_create(&td_plugin_list, NULL) != 0) {`
		`slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_plugin_list\n");`
		`return PR_FAILURE;`
		`}`

		`- if(PR_NewThreadPrivateIndex(&td_conn_id, NULL) == PR_FAILURE){`
		`- slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_conn_id\n");`
		`- return PR_FAILURE;`
		`- }`
		`-`
		`- if(PR_NewThreadPrivateIndex(&td_op_id, NULL) == PR_FAILURE){`
		`- slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_op_id\n");`
		`- return PR_FAILURE;`
		`- }`
		`-`
		`- if(PR_NewThreadPrivateIndex(&td_op_internal_id, NULL) == PR_FAILURE){`
		`- slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_op_internal_id\n");`
		`- return PR_FAILURE;`
		`- }`
		`-`
		`- if(PR_NewThreadPrivateIndex(&td_op_internal_nested_count, NULL) == PR_FAILURE){`
		`- slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_op_internal_nested_count\n");`
		`- return PR_FAILURE;`
		`- }`
		`-`
		`-`
		`- if(PR_NewThreadPrivateIndex(&td_op_internal_nested_state, NULL) == PR_FAILURE){`
		`- slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_op_internal_nested_state\n");`
		`- return PR_FAILURE;`
		`- }`
		`-`
		`- return PR_SUCCESS;`
		`- }`
		`-`
		`-`
		`-`
		`- /*`
		`- * Caller needs to cast value to (void *)`
		`- */`
		`- int`
		`- slapi_td_set_val(int indexType, void *value)`
		`- {`
		`- switch (indexType) {`
		`- case SLAPI_TD_REQUESTOR_DN:`
		`- if (td_requestor_dn) {`
		`- if (PR_SetThreadPrivate(td_requestor_dn, value) == PR_FAILURE) {`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_PLUGIN_LIST_LOCK:`
		`- if (td_plugin_list) {`
		`- if (PR_SetThreadPrivate(td_plugin_list, value) == PR_FAILURE) {`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_CONN_ID:`
		`- if(td_conn_id){`
		`- if(PR_SetThreadPrivate(td_conn_id, value) == PR_FAILURE){`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_ID:`
		`- if(td_op_id){`
		`- if(PR_SetThreadPrivate(td_op_id, value) == PR_FAILURE){`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_INTERNAL_ID:`
		`- if(td_op_internal_id){`
		`- if(PR_SetThreadPrivate(td_op_internal_id, value) == PR_FAILURE){`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_NESTED_COUNT:`
		`- if(td_op_internal_nested_count){`
		`- if(PR_SetThreadPrivate(td_op_internal_nested_count, value) == PR_FAILURE){`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_NESTED_STATE:`
		`- if(td_op_internal_nested_state){`
		`- if(PR_SetThreadPrivate(td_op_internal_nested_state, value) == PR_FAILURE){`
		`- return PR_FAILURE;`
		`- }`
		`- } else {`
		`- return PR_FAILURE;`
		`- }`
		`- break;`
		`- default:`
		`+ if(pthread_key_create(&td_op_state, td_op_state_destroy) != 0){`
		`+ slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_init", "Failed it create private thread index for td_op_state\n");`
		`return PR_FAILURE;`
		`}`

		`return PR_SUCCESS;`
		`}`

		`- /*`
		`- * Caller needs to cast value to (void **)`
		`- */`
		`- void`
		`- slapi_td_get_val(int indexType, void **value)`
		`- {`
		`- switch (indexType) {`
		`- case SLAPI_TD_REQUESTOR_DN:`
		`- if (td_requestor_dn) {`
		`- *value = PR_GetThreadPrivate(td_requestor_dn);`
		`- } else {`
		`- *value = NULL;`
		`- }`
		`- break;`
		`- case SLAPI_TD_PLUGIN_LIST_LOCK:`
		`- if (td_plugin_list) {`
		`- *value = PR_GetThreadPrivate(td_plugin_list);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- case SLAPI_TD_CONN_ID:`
		`- if(td_conn_id){`
		`- *value = PR_GetThreadPrivate(td_conn_id);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_ID:`
		`- if(td_op_id){`
		`- *value = PR_GetThreadPrivate(td_op_id);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_INTERNAL_ID:`
		`- if(td_op_internal_id){`
		`- *value = PR_GetThreadPrivate(td_op_internal_id);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_NESTED_COUNT:`
		`- if(td_op_internal_nested_count){`
		`- *value = PR_GetThreadPrivate(td_op_internal_nested_count);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- case SLAPI_TD_OP_NESTED_STATE:`
		`- if(td_op_internal_nested_state){`
		`- *value = PR_GetThreadPrivate(td_op_internal_nested_state);`
		`- } else {`
		`- *value = 0;`
		`- }`
		`- break;`
		`- default:`
		`- *value = NULL;`
		`- return;`
		`- }`
		`- }`

		`/*`
		`* Wrapper Functions`
		`*/`

		`/* plugin list locking */`
		`- int`
		`+ int32_t`
		`slapi_td_set_plugin_locked()`
		`{`
		`- int val = 12345;`
		`+ int32_t val = 12345;`

		`- if (slapi_td_set_val(SLAPI_TD_PLUGIN_LIST_LOCK, (void *)&val) == PR_FAILURE) {`
		`+ if (pthread_setspecific(td_plugin_list, (void *)&val) != 0) {`
		`return PR_FAILURE;`
		`}`

		`return PR_SUCCESS;`
		`}`

		`- int`
		`+ int32_t`
		`slapi_td_set_plugin_unlocked()`
		`{`
		`- if (slapi_td_set_val(SLAPI_TD_PLUGIN_LIST_LOCK, NULL) == PR_FAILURE) {`
		`+ if (pthread_setspecific(td_plugin_list, NULL) != 0) {`
		`return PR_FAILURE;`
		`}`

		`return PR_SUCCESS;`
		`}`

		`- int`
		`+ int32_t`
		`slapi_td_get_plugin_locked()`
		`{`
		`- int *value = 0;`
		`+ int32_t *value = pthread_getspecific(td_plugin_list);`

		`- slapi_td_get_val(SLAPI_TD_PLUGIN_LIST_LOCK, (void **)&value);`
		`- if (value) {`
		`- return 1;`
		`- } else {`
		`+ if (value == NULL) {`
		`return 0;`
		`}`
		`+ return 1;`
		`}`

		`/* requestor dn */`
		`- int`
		`+ int32_t`
		`slapi_td_set_dn(char *value)`
		`{`
		`- if (slapi_td_set_val(SLAPI_TD_REQUESTOR_DN, (void *)value) == PR_FAILURE) {`
		`+ if (pthread_setspecific(td_requestor_dn, value) != 0) {`
		`return PR_FAILURE;`
		`}`

		`@@ -289,9 +108,18 @@`
		`void`
		`slapi_td_get_dn(char **value)`
		`{`
		`- slapi_td_get_val(SLAPI_TD_REQUESTOR_DN, (void **)value);`
		`+ if (value) {`
		`+ *value = pthread_getspecific(td_requestor_dn);`
		`+ }`
		`+ }`
		`+`
		`+ /* Worker op-state */`
		`+ struct slapi_td_log_op_state_t *`
		`+ slapi_td_get_log_op_state() {`
		`+ return pthread_getspecific(td_op_state);`
		`}`

		`+`
		`/*`
		`* Increment the internal operation count. Since internal operations`
		`* can be nested via plugins calling plugins we need to keep track of`
		`@@ -302,43 +130,41 @@`
		`void`
		`slapi_td_internal_op_start(void)`
		`{`
		`- int32_t *id_count_ptr = NULL;`
		`- int32_t *nested_state_ptr = NULL;`
		`- int32_t *nested_count_ptr = NULL;`
		`- uint64_t *connid = NULL;`
		`-`
		`- slapi_td_get_val(SLAPI_TD_CONN_ID, (void **)&connid);`
		`- if (connid == NULL){`
		`- /* No connection id, just return */`
		`- return;`
		`+ struct slapi_td_log_op_state_t *op_state = pthread_getspecific(td_op_state);`
		`+`
		`+ /* Allocate if needed */`
		`+ if (op_state == NULL) {`
		`+ op_state = (struct slapi_td_log_op_state_t *)slapi_ch_calloc(1, sizeof(struct slapi_td_log_op_state_t));`
		`+ if (pthread_setspecific(td_op_state, op_state) != 0) {`
		`+ slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_internal_op_start",`
		`+ "Failed to set op_state to td_op_state. OOM?\n");`
		`+ return;`
		`+ }`
		`}`

		`/* increment the internal op id counter */`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID, (void **)&id_count_ptr);`
		`- (*id_count_ptr)++;`
		`+ op_state->op_int_id += 1;`

		`/*`
		`* Bump the nested count so we can maintain our counts after plugins call`
		`* plugins, etc.`
		`*/`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_COUNT, (void **)&nested_count_ptr);`
		`- (*nested_count_ptr)++;`
		`+ op_state->op_nest_count += 1;`

		`/* Now check for special cases in the nested count */`
		`- if (*nested_count_ptr == 2){`
		`+ if (op_state->op_nest_count == 2){`
		`/* We are now nested, mark it as so */`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_STATE, (void **)&nested_state_ptr);`
		`- *nested_state_ptr = NESTED;`
		`- } else if (*nested_count_ptr == 1) {`
		`+ /* THERE IS A BETTER WAY! We should track parent op structs instead! */`
		`+ op_state->op_nest_state = OP_STATE_NESTED;`
		`+ } else if (op_state->op_nest_count == 1) {`
		`/*`
		`* Back to the beginning, but if we were previously nested then the`
		`* internal op id count is off`
		`*/`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_STATE, (void **)&nested_state_ptr);`
		`- if (*nested_state_ptr == UNNESTED){`
		`+ if (op_state->op_nest_state == OP_STATE_UNNESTED){`
		`/* We were nested but anymore, need to bump the internal id count again */`
		`- nested_state_ptr = NOTNESTED; / reset nested state */`
		`- (*id_count_ptr)++;`
		`+ op_state->op_nest_state = OP_STATE_NOTNESTED; /* reset nested state */`
		`+ op_state->op_int_id += 1;`
		`}`
		`}`
		`}`
		`@@ -352,24 +178,24 @@`
		`void`
		`slapi_td_internal_op_finish(void)`
		`{`
		`- int32_t *nested_count_ptr = NULL;`
		`- int32_t *nested_state_ptr = NULL;`
		`- int32_t *id_count_ptr = NULL;`
		`- uint64_t *connid = NULL;`
		`-`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID, (void **)&connid);`
		`- if (connid == NULL){`
		`- /* No connection id, just return */`
		`- return;`
		`+ struct slapi_td_log_op_state_t *op_state = pthread_getspecific(td_op_state);`
		`+`
		`+ /* Allocate if needed - should be unreachable!*/`
		`+ PR_ASSERT(op_state);`
		`+ if (op_state == NULL) {`
		`+ op_state = (struct slapi_td_log_op_state_t *)slapi_ch_calloc(1, sizeof(struct slapi_td_log_op_state_t));`
		`+ if (pthread_setspecific(td_op_state, op_state) != 0) {`
		`+ slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_internal_op_finish",`
		`+ "Failed to set op_state to td_op_state. OOM?\n");`
		`+ return;`
		`+ }`
		`}`

		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_COUNT, (void **)&nested_count_ptr);`
		`- if ( *nested_count_ptr > 1 ){`
		`+ if ( op_state->op_nest_count > 1 ){`
		`/* Nested op just finished, decr op id */`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID, (void **)&id_count_ptr);`
		`- (*id_count_ptr)--;`
		`+ op_state->op_int_id -= 1;`

		`- if ( (*nested_count_ptr - 1) == 1 ){`
		`+ if ( (op_state->op_nest_count - 1) == 1 ){`
		`/*`
		`* Okay we are back to the beginning, We were nested but not`
		`* anymore. So when we start the next internal op on this`
		`@@ -377,81 +203,30 @@`
		`* maintain the correct op id sequence. Set the nested state`
		`* to "unnested".`
		`*/`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_STATE, (void **)&nested_state_ptr);`
		`- *nested_state_ptr = UNNESTED;`
		`+ op_state->op_nest_state = OP_STATE_UNNESTED;`
		`}`
		`}`
		`/* decrement nested count */`
		`- (*nested_count_ptr)--;`
		`- }`
		`-`
		`- void`
		`- slapi_td_init_internal_logging(void)`
		`- {`
		`- uint64_t conn_id = (uint64_t )slapi_ch_calloc(1, sizeof(uint64_t));`
		`- int32_t op_id = (int32_t )slapi_ch_calloc(1, sizeof(int32_t));`
		`- int32_t internal_op_id = (int32_t )slapi_ch_calloc(1, sizeof(int32_t));`
		`- int32_t nested_count = (int32_t )slapi_ch_calloc(1, sizeof(int32_t));`
		`- int32_t nested_state = (int32_t )slapi_ch_calloc(1, sizeof(int32_t));`
		`-`
		`- slapi_td_set_val(SLAPI_TD_CONN_ID, (void *)conn_id);`
		`- slapi_td_set_val(SLAPI_TD_OP_ID, (void *)op_id);`
		`- slapi_td_set_val(SLAPI_TD_OP_INTERNAL_ID, (void *)internal_op_id);`
		`- slapi_td_set_val(SLAPI_TD_OP_NESTED_COUNT, (void *)nested_count);`
		`- slapi_td_set_val(SLAPI_TD_OP_NESTED_STATE, (void *)nested_state);`
		`+ op_state->op_nest_count -= 1;`
		`}`

		`void`
		`slapi_td_reset_internal_logging(uint64_t new_conn_id, int32_t new_op_id)`
		`{`
		`- uint64_t *conn_id;`
		`- int32_t *op_id;`
		`- int32_t *internal_op_id;`
		`- int32_t *nested_count;`
		`- int32_t *nested_state;`
		`-`
		`- slapi_td_get_val(SLAPI_TD_CONN_ID, (void **)&conn_id);`
		`- slapi_td_get_val(SLAPI_TD_OP_ID, (void **)&op_id);`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID, (void **)&internal_op_id);`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_COUNT, (void **)&nested_count);`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_STATE, (void **)&nested_state);`
		`-`
		`- *conn_id = new_conn_id;`
		`- *op_id = new_op_id;`
		`- *internal_op_id = 0;`
		`- *nested_count = 0;`
		`- *nested_state = 0;`
		`- }`
		`-`
		`- void`
		`- slapi_td_free_internal_logging(void)`
		`- {`
		`- uint64_t *conn_id = NULL;`
		`- int32_t *val = NULL;`
		`-`
		`- slapi_td_get_val(SLAPI_TD_CONN_ID, (void **)&conn_id);`
		`- slapi_ch_free((void **)&conn_id);`
		`-`
		`- slapi_td_get_val(SLAPI_TD_OP_ID, (void **)&val);`
		`- slapi_ch_free((void **)&val);`
		`-`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID, (void **)&val);`
		`- slapi_ch_free((void **)&val);`
		`-`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_COUNT, (void **)&val);`
		`- slapi_ch_free((void **)&val);`
		`-`
		`- slapi_td_get_val(SLAPI_TD_OP_NESTED_STATE, (void **)&val);`
		`- slapi_ch_free((void **)&val);`
		`- }`
		`-`
		`- /*`
		`- * Destructor Functions`
		`- */`
		`-`
		`- void`
		`- td_dn_destructor(void *priv)`
		`- {`
		`- slapi_ch_free((void **)&priv);`
		`+ struct slapi_td_log_op_state_t *op_state = pthread_getspecific(td_op_state);`
		`+`
		`+ /* Allocate if needed */`
		`+ if (op_state == NULL) {`
		`+ op_state = (struct slapi_td_log_op_state_t *)slapi_ch_calloc(1, sizeof(struct slapi_td_log_op_state_t));`
		`+ if (pthread_setspecific(td_op_state, op_state) != 0) {`
		`+ slapi_log_err(SLAPI_LOG_CRIT, "slapi_td_internal_op_finish",`
		`+ "Failed to set op_state to td_op_state. OOM?\n");`
		`+ return;`
		`+ }`
		`+ }`
		`+ op_state->conn_id = new_conn_id;`
		`+ op_state->op_id = new_op_id;`
		`+ op_state->op_int_id = 0;`
		`+ op_state->op_nest_count = 0;`
		`+ op_state->op_nest_state = OP_STATE_NOTNESTED;`
		`}`
		`-`

ldap/servers/slapd/util.c

file modified

+10 -25

		`@@ -1591,31 +1591,16 @@`
		`}`

		`void`
		`- get_internal_conn_op (uint64_t connid, int32_t op_id, int32_t *op_internal_id)`
		`- {`
		`- uint64_t default_id = 0;`
		`- uint64_t *td_conn;`
		`-`
		`- slapi_td_get_val(SLAPI_TD_CONN_ID,(void **)&td_conn);`
		`- if (td_conn) {`
		`- int32_t *td_op;`
		`- int32_t *td_internal_op;`
		`- connid = td_conn;`
		`- slapi_td_get_val(SLAPI_TD_OP_ID,(void **)&td_op);`
		`- if (td_op) {`
		`- op_id = td_op;`
		`- } else {`
		`- *op_id = default_id;`
		`- }`
		`- slapi_td_get_val(SLAPI_TD_OP_INTERNAL_ID,(void **)&td_internal_op);`
		`- if (td_internal_op){`
		`- op_internal_id = td_internal_op;`
		`- } else {`
		`- *op_internal_id = default_id;`
		`- }`
		`+ get_internal_conn_op (uint64_t connid, int32_t op_id, int32_t *op_internal_id) {`
		`+ struct slapi_td_log_op_state_t *op_state = slapi_td_get_log_op_state();`
		`+`
		`+ if (op_state != NULL) {`
firstyear commented 5 years ago In the original version of util.c due to the nature of the pointers this check (confusingly) was checking td_conn - I read it as "is td_conn > 0" rather than "is td_conn a valid pointer". So my check would check connid > 0 and op_state != null. THis caused all op_id's to follow the second branch, This now checks only the struct pointer instead, and it cleans the issues up
		`+ *connid = op_state->conn_id;`
		`+ *op_id = op_state->op_id;`
		`+ *op_internal_id = op_state->op_int_id;`
		`} else {`
		`- *connid = default_id;`
		`- *op_id = default_id;`
		`- *op_internal_id = default_id;`
		`+ *connid = 0;`
		`+ *op_id = 0;`
		`+ *op_internal_id = 0;`
		`}`
		`}`

firstyear commented 5 years ago

Clean the thread local usage of the logging system to be more inline with
pthread's intent, remove bad practices of case/switch get setters, and change
the types to be more effecient struct types. Generally make it better

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

Author: William Brown william@blackhats.net.au

rebased onto db4c991229ac587d776908fbf2697235d2ea4317

5 years ago

rebased onto db4c991229ac587d776908fbf2697235d2ea4317

5 years ago

mreynolds commented 5 years ago

This patch breaks the internal operation logging. Its not incrementing the op count for internal operations that are done outside of worker threads. That's why in main.c I had an explicit initialization for the main thread.

[07/Sep/2018:11:19:23.448696877 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=1 etime=0.0000101904
[07/Sep/2018:11:19:23.452060677 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0003609864
[07/Sep/2018:11:19:23.456748531 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:19:23.457938971 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0001214719
[07/Sep/2018:11:19:53.461206310 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:19:53.468369376 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0007184712
[07/Sep/2018:11:20:23.472024900 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:20:23.475223861 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0003228102

This should look like:

[07/Sep/2018:11:39:43.687726972 -0400] conn=Internal(0) op=0(102) RESULT err=0 tag=48 nentries=0 etime=0.0000024356
[07/Sep/2018:11:39:43.687750902 -0400] conn=Internal(0) op=0(103) ADD dn="cn=monitor,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687790827 -0400] conn=Internal(0) op=0(103) RESULT err=68 tag=48 nentries=0 etime=0.0000045336
[07/Sep/2018:11:39:43.687804508 -0400] conn=Internal(0) op=0(104) ADD dn="cn=index,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687833521 -0400] conn=Internal(0) op=0(104) RESULT err=68 tag=48 nentries=0 etime=0.0000032260
[07/Sep/2018:11:39:43.687846597 -0400] conn=Internal(0) op=0(105) ADD dn="cn=encrypted attributes,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687873425 -0400] conn=Internal(0) op=0(105) RESULT err=68 tag=48 nentries=0 etime=0.0000030488

Simply restarting the server will show the difference in behavior with and without your patch.

firstyear commented 5 years ago

@mreynolds Thanks for checking - I'll look into why this is.

firstyear commented 5 years ago

Okay, when you say "outside of worker threads" what do you mean? all threads in this new setup are "workers" now - they initialise on first use rather that explicit init. So long as the _start() function is called, they get a valid structure. I would suspect that it's something else going on that I need to check into. How did you create the conditions here to highlight this issue?

firstyear commented 5 years ago

[08/Sep/2018:16:50:55.903789304 +1000] conn=Internal(0) op=0(80) SRCH base="cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=0 filter="objectclass=*" attrs=ALL
[08/Sep/2018:16:50:55.904022552 +1000] conn=Internal(0) op=0(80) RESULT err=0 tag=48 nentries=1 etime=0.0000258169
[08/Sep/2018:16:50:55.906507206 +1000] conn=Internal(0) op=0(81) SRCH base="cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=2 filter="(objectclass=nsIndex)" attrs=ALL
[08/Sep/2018:16:50:55.909551731 +1000] conn=Internal(0) op=0(81) RESULT err=0 tag=48 nentries=27 etime=0.0003070941
[08/Sep/2018:16:50:55.910020883 +1000] conn=Internal(0) op=0(82) SRCH base="cn=encrypted attributes,cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=2 filter="(objectclass=nsAttributeEncryption)" attrs=ALL

Fixed, code incoming,

rebased onto dc9e2c4371329d69a77b6fc25091e628014b827a

5 years ago

firstyear commented on line 30 of ldap/servers/slapd/util.c 5 years ago

In the original version of util.c due to the nature of the pointers this check (confusingly) was checking td_conn - I read it as "is td_conn > 0" rather than "is td_conn a valid pointer". So my check would check connid > 0 and op_state != null. THis caused all op_id's to follow the second branch,

This now checks only the struct pointer instead, and it cleans the issues up

firstyear commented 5 years ago

In general I think this could be redesigned to use Op struct pointer checks rather than thread local, but I only have so much time in a day.

mreynolds commented 5 years ago

Thanks - LGTM!! Ack!

firstyear commented 5 years ago

Thank you! I'll rebase and merge :)

rebased onto e59b309

5 years ago

Pull-Request has been merged by firstyear

5 years ago

mreynolds commented 5 years ago

Turns out internal operation logging is still completely broken. The op numbers and counts are wrong and not reliable :-( Investigating this in https://pagure.io/389-ds-base/issue/49995