From bab9a88f08bca6c7679db38ab442b5414130c929 Mon Sep 17 00:00:00 2001
From: Ludwig Krispenz <lkrispen@redhat.com>
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

