From: Pavel Filipenský <pfilipen@redhat.com>
Date: Tue, 7 Jun 2022 17:33:57 +0000 (+0200)
Subject: s3:winbind: Improve logging in wb_gettoken.c
X-Git-Tag: tevent-0.13.0~123
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=42ada8ed1cbcf9fc73edd6baefd97ed3a61df21f;p=thirdparty%2Fsamba.git

s3:winbind: Improve logging in wb_gettoken.c

Signed-off-by: Pavel Filipenský <pfilipen@redhat.com>
Reviewed-by: Andreas Schneider <asn@samba.org>
---

diff --git a/source3/winbindd/wb_gettoken.c b/source3/winbindd/wb_gettoken.c
index a393b0f09e7..c0b61c25a9a 100644
--- a/source3/winbindd/wb_gettoken.c
+++ b/source3/winbindd/wb_gettoken.c
@@ -18,6 +18,7 @@
 */
 
 #include "includes.h"
+#include "util/debug.h"
 #include "winbindd.h"
 #include "librpc/gen_ndr/ndr_winbind_c.h"
 #include "../libcli/security/security.h"
@@ -49,6 +50,7 @@ struct tevent_req *wb_gettoken_send(TALLOC_CTX *mem_ctx,
 {
 	struct tevent_req *req, *subreq;
 	struct wb_gettoken_state *state;
+	struct dom_sid_buf buf;
 
 	req = tevent_req_create(mem_ctx, &state, struct wb_gettoken_state);
 	if (req == NULL) {
@@ -58,6 +60,10 @@ struct tevent_req *wb_gettoken_send(TALLOC_CTX *mem_ctx,
 	state->ev = ev;
 	state->expand_local_aliases = expand_local_aliases;
 
+	D_INFO("WB command gettoken start.\n"
+	       "Query user SID %s (expand local aliases is %d).\n",
+	       dom_sid_str_buf(sid, &buf),
+	       expand_local_aliases);
 	subreq = wb_queryuser_send(state, ev, &state->usersid);
 	if (tevent_req_nomem(subreq, req)) {
 		return tevent_req_post(req, ev);
@@ -74,6 +80,7 @@ static void wb_gettoken_gotuser(struct tevent_req *subreq)
 		req, struct wb_gettoken_state);
 	struct wbint_userinfo *info;
 	NTSTATUS status;
+	struct dom_sid_buf buf0, buf1;
 
 	status = wb_queryuser_recv(subreq, state, &info);
 	TALLOC_FREE(subreq);
@@ -87,9 +94,13 @@ static void wb_gettoken_gotuser(struct tevent_req *subreq)
 	}
 	state->num_sids = 2;
 
+	D_DEBUG("Got user SID %s and group SID %s\n",
+		  dom_sid_str_buf(&info->user_sid, &buf0),
+		  dom_sid_str_buf(&info->group_sid, &buf1));
 	sid_copy(&state->sids[0], &info->user_sid);
 	sid_copy(&state->sids[1], &info->group_sid);
 
+	D_DEBUG("Looking up user groups for the user SID.\n");
 	subreq = wb_lookupusergroups_send(state, state->ev, &info->user_sid);
 	if (tevent_req_nomem(subreq, req)) {
 		return;
@@ -107,6 +118,7 @@ static void wb_gettoken_gotgroups(struct tevent_req *subreq)
 	struct dom_sid *groups;
 	struct winbindd_domain *domain;
 	NTSTATUS status;
+	struct dom_sid_buf buf;
 
 	status = wb_lookupusergroups_recv(subreq, state, &num_groups, &groups);
 	TALLOC_FREE(subreq);
@@ -115,7 +127,9 @@ static void wb_gettoken_gotgroups(struct tevent_req *subreq)
 		return;
 	}
 
-	for (i=0; i<num_groups; i++) {
+	D_DEBUG("Received %d group(s).\n", num_groups);
+	for (i = 0; i < num_groups; i++) {
+		D_DEBUG("Adding SID %s.\n", dom_sid_str_buf(&groups[i], &buf));
 		status = add_sid_to_array_unique(
 			state, &groups[i], &state->sids, &state->num_sids);
 
@@ -125,6 +139,7 @@ static void wb_gettoken_gotgroups(struct tevent_req *subreq)
 	}
 
 	if (!state->expand_local_aliases) {
+		D_DEBUG("Done. Not asked to expand local aliases.\n");
 		tevent_req_done(req);
 		return;
 	}
@@ -138,6 +153,7 @@ static void wb_gettoken_gotgroups(struct tevent_req *subreq)
 		return;
 	}
 
+	D_DEBUG("Expand domain's aliases for %d  SIDs.\n", state->num_sids);
 	subreq = wb_lookupuseraliases_send(state, state->ev, domain,
 					   state->num_sids, state->sids);
 	if (tevent_req_nomem(subreq, req)) {
@@ -163,6 +179,7 @@ static void wb_gettoken_gotlocalgroups(struct tevent_req *subreq)
 		return;
 	}
 
+	D_DEBUG("Got %d RID(s).\n", num_rids);
 	status = wb_add_rids_to_sids(state, &state->num_sids, &state->sids,
 				     get_global_sam_sid(), num_rids, rids);
 	if (tevent_req_nterror(req, status)) {
@@ -174,6 +191,7 @@ static void wb_gettoken_gotlocalgroups(struct tevent_req *subreq)
 	 * Now expand the builtin groups
 	 */
 
+	D_DEBUG("Expand the builtin groups for %d SID(s).\n", state->num_sids);
 	domain = find_domain_from_sid(&global_sid_Builtin);
 	if (domain == NULL) {
 		tevent_req_nterror(req, NT_STATUS_INTERNAL_ERROR);
@@ -203,6 +221,7 @@ static void wb_gettoken_gotbuiltins(struct tevent_req *subreq)
 	if (tevent_req_nterror(req, status)) {
 		return;
 	}
+	D_DEBUG("Got %d RID(s).\n", num_rids);
 	status = wb_add_rids_to_sids(state, &state->num_sids, &state->sids,
 				     &global_sid_Builtin, num_rids, rids);
 	if (tevent_req_nterror(req, status)) {
@@ -217,11 +236,18 @@ NTSTATUS wb_gettoken_recv(struct tevent_req *req, TALLOC_CTX *mem_ctx,
 	struct wb_gettoken_state *state = tevent_req_data(
 		req, struct wb_gettoken_state);
 	NTSTATUS status;
+	int i;
 
 	if (tevent_req_is_nterror(req, &status)) {
 		return status;
 	}
 	*num_sids = state->num_sids;
+	D_INFO("WB command gettoken end.\nReceived %d SID(s).\n", state->num_sids);
+	for (i = 0; i < state->num_sids; i++) {
+		struct dom_sid_buf sidbuf;
+		D_INFO("%d: %s\n", i, dom_sid_str_buf(&state->sids[i], &sidbuf));
+	}
+
 	*sids = talloc_move(mem_ctx, &state->sids);
 	return NT_STATUS_OK;
 }
@@ -233,8 +259,10 @@ static NTSTATUS wb_add_rids_to_sids(TALLOC_CTX *mem_ctx,
 				    int num_rids, uint32_t *rids)
 {
 	int i;
-
-	for (i=0; i<num_rids; i++) {
+	D_DEBUG("%u SID(s) will be uniquely added to the SID array.\n"
+		"Before the addition the array has %d SID(s).\n",
+		num_rids, *pnum_sids);
+	for (i = 0; i < num_rids; i++) {
 		NTSTATUS status;
 		struct dom_sid sid;
 
@@ -246,6 +274,6 @@ static NTSTATUS wb_add_rids_to_sids(TALLOC_CTX *mem_ctx,
 			return status;
 		}
 	}
-
+	D_DEBUG("After the addition the array has %d SID(s).\n", *pnum_sids);
 	return NT_STATUS_OK;
 }