From bab9a88f08bca6c7679db38ab442b5414130c929 Mon Sep 17 00:00:00 2001 From: Ludwig Krispenz Date: Thu, 3 Nov 2016 17:12:20 +0100 Subject: [PATCH] improve logging of internal operations - POC --- ldap/servers/slapd/connection.c | 8 +++++ ldap/servers/slapd/main.c | 2 ++ ldap/servers/slapd/opshared.c | 21 +++++++++++-- ldap/servers/slapd/pblock.c | 15 +++++++-- ldap/servers/slapd/slapi-plugin.h | 4 +++ ldap/servers/slapd/thread_data.c | 65 ++++++++++++++++++++++++++++++++++++++- 6 files changed, 109 insertions(+), 6 deletions(-) diff --git a/ldap/servers/slapd/connection.c b/ldap/servers/slapd/connection.c index 51eb694..989406b 100644 --- a/ldap/servers/slapd/connection.c +++ b/ldap/servers/slapd/connection.c @@ -1506,6 +1506,8 @@ connection_threadmain() int maxthreads = 0; int enable_nunc_stans = 0; long bypasspollcnt = 0; + PRUint64 td_conn_id; + int td_op_id; #ifdef ENABLE_NUNC_STANS enable_nunc_stans = config_get_enable_nunc_stans(); @@ -1600,6 +1602,10 @@ connection_threadmain() /* Once we're here we have a pb */ conn = pb->pb_conn; op = pb->pb_op; + td_conn_id = conn->c_connid; + td_op_id = op->o_opid; + slapi_td_set_val(SLAPI_TD_CONN_ID,(void *)&td_conn_id); + slapi_td_set_val(SLAPI_TD_OP_ID,(void *)&td_op_id); maxthreads = config_get_maxthreadsperconn(); more_data = 0; ret = connection_read_operation(conn, op, &tag, &more_data); @@ -1779,6 +1785,8 @@ done: * there's more work to do right now on this conn. */ + slapi_td_set_val(SLAPI_TD_CONN_ID,NULL); + slapi_td_set_val(SLAPI_TD_OP_ID,NULL); /* number of ops on this connection */ PR_AtomicIncrement(&conn->c_opscompleted); /* total number of ops for the server */ diff --git a/ldap/servers/slapd/main.c b/ldap/servers/slapd/main.c index 78f21d0..19ea297 100644 --- a/ldap/servers/slapd/main.c +++ b/ldap/servers/slapd/main.c @@ -1069,6 +1069,8 @@ main( int argc, char **argv) /* init the thread data indexes */ slapi_td_dn_init(); slapi_td_plugin_lock_init(); + slapi_td_conn_id_init(); + slapi_td_op_id_init(); /* * Initialize password storage in entry extension. diff --git a/ldap/servers/slapd/opshared.c b/ldap/servers/slapd/opshared.c index 3ce7970..59172e9 100644 --- a/ldap/servers/slapd/opshared.c +++ b/ldap/servers/slapd/opshared.c @@ -290,7 +290,8 @@ op_shared_search (Slapi_PBlock *pb, int send_result) char *fmtstr; #define SLAPD_SEARCH_FMTSTR_BASE "conn=%" NSPRIu64 " op=%d SRCH base=\"%s\" scope=%d " -#define SLAPD_SEARCH_FMTSTR_BASE_INT "conn=%s op=%d SRCH base=\"%s\" scope=%d " +#define SLAPD_SEARCH_FMTSTR_BASE_INT "conn=%" NSPRIu64 " op=%d SRCH (internal) base=\"%s\" scope=%d " +/* #define SLAPD_SEARCH_FMTSTR_BASE_INT "conn=%s op=%d SRCH base=\"%s\" scope=%d " */ #define SLAPD_SEARCH_FMTSTR_REMAINDER " attrs=%s%s%s\n" PR_ASSERT(fstr); @@ -345,9 +346,23 @@ op_shared_search (Slapi_PBlock *pb, int send_result) } else { + int log_op = LOG_INTERNAL_OP_OP_ID; + PRUint64 log_conn; + PRUint64 *pb_conn; + slapi_td_get_val(SLAPI_TD_CONN_ID,(void **)&pb_conn); + if (pb_conn) { + int *pb_op; + log_conn = *pb_conn; + slapi_td_get_val(SLAPI_TD_OP_ID,(void **)&pb_op); + if (pb_op) log_op = *pb_op; + else log_op = LOG_INTERNAL_OP_OP_ID; + } else { + log_conn = -1; + } + slapi_log_access(LDAP_DEBUG_ARGS, fmtstr, - LOG_INTERNAL_OP_CON_ID, - LOG_INTERNAL_OP_OP_ID, + log_conn, + log_op, normbase, scope, fstr, attrliststr, flag_psearch ? " options=persistent" : "", diff --git a/ldap/servers/slapd/pblock.c b/ldap/servers/slapd/pblock.c index dcac322..01ab6ab 100644 --- a/ldap/servers/slapd/pblock.c +++ b/ldap/servers/slapd/pblock.c @@ -157,9 +157,13 @@ slapi_pblock_get( Slapi_PBlock *pblock, int arg, void *value ) break; case SLAPI_CONN_ID: if (pblock->pb_conn == NULL) { + PRUint64 *pb_conn; slapi_log_err(SLAPI_LOG_TRACE, "slapi_pblock_get", "Connection is NULL and hence cannot access SLAPI_CONN_ID \n"); - return (-1); + slapi_td_get_val(SLAPI_TD_CONN_ID,(void **)&pb_conn); + if (pb_conn) (*(PRUint64 *)value) = *pb_conn; + else (*(PRUint64 *)value) = -1; + break; } (*(PRUint64 *)value) = pblock->pb_conn->c_connid; break; @@ -1850,7 +1854,14 @@ slapi_pblock_get( Slapi_PBlock *pblock, int arg, void *value ) break; case SLAPI_OPERATION_ID: if (pblock->pb_op != NULL) { - (*(int *)value ) = pblock->pb_op->o_opid; + if (pblock->pb_op->o_opid) { + (*(int *)value ) = pblock->pb_op->o_opid; + } else { + int *pb_op; + slapi_td_get_val(SLAPI_TD_OP_ID,(void **)&pb_op); + if (pb_op) (*(int *)value ) = *pb_op; + else (*(int *)value ) = 0; + } } break; /* Command line arguments */ diff --git a/ldap/servers/slapd/slapi-plugin.h b/ldap/servers/slapd/slapi-plugin.h index f4253de..f057c1f 100644 --- a/ldap/servers/slapd/slapi-plugin.h +++ b/ldap/servers/slapd/slapi-plugin.h @@ -5577,11 +5577,15 @@ 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); +int slapi_td_conn_id_init(void); +int slapi_td_op_id_init(void); /* Thread Local Storage Index Types */ #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 /* * routines for dealing with controls diff --git a/ldap/servers/slapd/thread_data.c b/ldap/servers/slapd/thread_data.c index 46a0c20..5b70039 100644 --- a/ldap/servers/slapd/thread_data.c +++ b/ldap/servers/slapd/thread_data.c @@ -19,6 +19,8 @@ void td_dn_destructor(void *priv); */ 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; /* * Index types defined in slapi-plugin.h @@ -52,7 +54,17 @@ slapi_td_init(int indexType) } break; case SLAPI_TD_PLUGIN_LIST_LOCK: - if(PR_NewThreadPrivateIndex(&td_plugin_list, NULL) == PR_FAILURE){ + if(PR_NewThreadPrivateIndex(&td_plugin_list, NULL) == PR_FAILURE){ + return PR_FAILURE; + } + break; + case SLAPI_TD_CONN_ID: + if(PR_NewThreadPrivateIndex(&td_conn_id, NULL) == PR_FAILURE){ + return PR_FAILURE; + } + break; + case SLAPI_TD_OP_ID: + if(PR_NewThreadPrivateIndex(&td_op_id, NULL) == PR_FAILURE){ return PR_FAILURE; } break; @@ -89,6 +101,24 @@ slapi_td_set_val(int indexType, void *value) return PR_FAILURE; } break; + case SLAPI_TD_CONN_ID: + if(td_plugin_list){ + if(PR_SetThreadPrivate(td_conn_id, value) == PR_FAILURE){ + return PR_FAILURE; + } + } else { + return PR_FAILURE; + } + break; + case SLAPI_TD_OP_ID: + if(td_plugin_list){ + if(PR_SetThreadPrivate(td_op_id, value) == PR_FAILURE){ + return PR_FAILURE; + } + } else { + return PR_FAILURE; + } + break; default: return PR_FAILURE; } @@ -117,6 +147,20 @@ slapi_td_get_val(int indexType, void **value) *value = 0; } break; + case SLAPI_TD_CONN_ID: + if(td_conn_id){ + *value = PR_GetThreadPrivate(td_conn_id); + } else { + *value = NULL; + } + break; + case SLAPI_TD_OP_ID: + if(td_op_id){ + *value = PR_GetThreadPrivate(td_op_id); + } else { + *value = NULL; + } + break; default: *value = NULL; return; @@ -211,4 +255,23 @@ td_dn_destructor(void *priv) slapi_ch_free((void **)&priv); } +/* connection id */ +int +slapi_td_conn_id_init() +{ + if(slapi_td_init(SLAPI_TD_CONN_ID) == PR_FAILURE){ + return PR_FAILURE; + } + + return PR_SUCCESS; +} +/* operation id */ +int +slapi_td_op_id_init() +{ + if(slapi_td_init(SLAPI_TD_OP_ID) == PR_FAILURE){ + return PR_FAILURE; + } + return PR_SUCCESS; +} -- 2.4.3