DP: Propagate down the client id and sender name

Make the client ID and responder name available to log where the DP request is attached. This will ensure we log the CID, originating responder name, and DP-internal request ID for all DP requests. [dp_attach_req] (0x0400): DP Request [Initgroups #14]: REQ_TRACE: New request. [sssd.pam CID #1] Flags [0x0001]. Reviewed-by: Sumit Bose <[email protected]>
SSSD · Jun 8, 2021 · 4f1a06d · 4f1a06d
1 parent d0e3589
commit 4f1a06d
Show file tree

Hide file tree

Showing 14 changed files with 82 additions and 47 deletions.
diff --git a/src/providers/data_provider/dp_private.h b/src/providers/data_provider/dp_private.h
@@ -30,6 +30,10 @@
 #define DP_REQ_DEBUG(level, name, fmt, ...) \
     DEBUG(level, "DP Request [%s]: " fmt "\n", (name ?: "Unknown"), ##__VA_ARGS__)
 
+/* Tracing message, changing this can break log parsing tools */
+#define SSS_REQ_TRACE_CID_DP_REQ(level, name, fmt, ...) \
+    DP_REQ_DEBUG(level, name, "REQ_TRACE: " fmt, ##__VA_ARGS__)
+
 enum dp_clients {
     DPC_NSS,
     DPC_PAM,

diff --git a/src/providers/data_provider/dp_request.c b/src/providers/data_provider/dp_request.c
@@ -103,7 +103,9 @@ static int dp_req_destructor(struct dp_req *dp_req)
 static errno_t dp_attach_req(struct dp_req *dp_req,
                              struct data_provider *provider,
                              const char *name,
-                             uint32_t dp_flags)
+                             uint32_t dp_flags,
+                             uint32_t cli_id,
+                             const char *sender_name)
 {
     /* If we run out of numbers we simply overflow. */
     dp_req->num = provider->requests.index++;
@@ -118,8 +120,15 @@ static errno_t dp_attach_req(struct dp_req *dp_req,
 
     talloc_set_destructor(dp_req, dp_req_destructor);
 
-    DP_REQ_DEBUG(SSSDBG_TRACE_FUNC, dp_req->name,
-                 "New request. Flags [%#.4x].", dp_flags);
+    if (cli_id > 0) {
+        SSS_REQ_TRACE_CID_DP_REQ(SSSDBG_TRACE_FUNC, dp_req->name,
+                                 "New request. [%s CID #%u] Flags [%#.4x].",
+                                 sender_name, cli_id, dp_flags);
+    } else {
+        SSS_REQ_TRACE_CID_DP_REQ(SSSDBG_TRACE_FUNC, dp_req->name,
+                                 "New request. Flags [%#.4x].",
+                                 dp_flags);
+    }
 
     DEBUG(SSSDBG_TRACE_FUNC, "Number of active DP request: %u\n",
           provider->requests.num_active);
@@ -132,6 +141,8 @@ dp_req_new(TALLOC_CTX *mem_ctx,
            struct data_provider *provider,
            const char *domainname,
            const char *name,
+           uint32_t cli_id,
+           const char *sender_name,
            enum dp_targets target,
            enum dp_methods method,
            uint32_t dp_flags,
@@ -158,7 +169,7 @@ dp_req_new(TALLOC_CTX *mem_ctx,
     dp_req->request_data = request_data;
     dp_req->req = req;
 
-    ret = dp_attach_req(dp_req, provider, name, dp_flags);
+    ret = dp_attach_req(dp_req, provider, name, dp_flags, cli_id, sender_name);
     if (ret != EOK) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create DP request "
               "[%s] [%d]: %s\n", name, ret, sss_strerror(ret));
@@ -192,6 +203,8 @@ file_dp_request(TALLOC_CTX *mem_ctx,
                 struct data_provider *provider,
                 const char *domainname,
                 const char *name,
+                uint32_t cli_id,
+                const char *sender_name,
                 enum dp_targets target,
                 enum dp_methods method,
                 uint32_t dp_flags,
@@ -207,8 +220,8 @@ file_dp_request(TALLOC_CTX *mem_ctx,
 
     be_ctx = provider->be_ctx;
 
-    ret = dp_req_new(mem_ctx, provider, domainname, name, target,
-                     method, dp_flags, request_data, req, &dp_req);
+    ret = dp_req_new(mem_ctx, provider, domainname, name, cli_id, sender_name,
+                     target, method, dp_flags, request_data, req, &dp_req);
     if (ret != EOK) {
         *_dp_req = dp_req;
         goto done;
@@ -274,6 +287,8 @@ struct tevent_req *dp_req_send(TALLOC_CTX *mem_ctx,
                                struct data_provider *provider,
                                const char *domain,
                                const char *name,
+                               uint32_t cli_id,
+                               const char *sender_name,
                                enum dp_targets target,
                                enum dp_methods method,
                                uint32_t dp_flags,
@@ -292,8 +307,8 @@ struct tevent_req *dp_req_send(TALLOC_CTX *mem_ctx,
         return NULL;
     }
 
-    ret = file_dp_request(state, provider, domain, name, target,
-                          method, dp_flags, request_data, req, &dp_req);
+    ret = file_dp_request(state, provider, domain, name, cli_id, sender_name,
+                          target, method, dp_flags, request_data, req, &dp_req);
 
     if (dp_req == NULL) {
         /* An error occurred before request could be created. */

diff --git a/src/providers/data_provider/dp_request.h b/src/providers/data_provider/dp_request.h
@@ -33,6 +33,8 @@ struct tevent_req *dp_req_send(TALLOC_CTX *mem_ctx,
                                struct data_provider *provider,
                                const char *domain,
                                const char *name,
+                               uint32_t cli_id,
+                               const char *sender_name,
                                enum dp_targets target,
                                enum dp_methods method,
                                uint32_t dp_flags,

diff --git a/src/providers/data_provider/dp_target_auth.c b/src/providers/data_provider/dp_target_auth.c
@@ -177,8 +177,9 @@ dp_pam_handler_send(TALLOC_CTX *mem_ctx,
         goto done;
     }
 
-    subreq = dp_req_send(state, provider, pd->domain, req_name, target,
-                         method, 0, pd, NULL);
+    subreq = dp_req_send(state, provider, pd->domain, req_name,
+                         pd->client_id_num, sbus_req->sender->name,
+                         target, method, 0, pd, NULL);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;
@@ -223,8 +224,9 @@ static void dp_pam_handler_auth_done(struct tevent_req *subreq)
     }
 
     subreq = dp_req_send(state, state->provider, state->pd->domain,
-                         "PAM SELinux", DPT_SELINUX, DPM_SELINUX_HANDLER,
-                         0, state->pd, NULL);
+                         "PAM SELinux", state->pd->client_id_num,
+                         "sssd.pam", DPT_SELINUX,
+                         DPM_SELINUX_HANDLER, 0, state->pd, NULL);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         tevent_req_error(req, ENOMEM);
@@ -292,7 +294,8 @@ dp_access_control_refresh_rules_send(TALLOC_CTX *mem_ctx,
     }
 
     subreq = dp_req_send(state, provider, NULL, "Refresh Access Control Rules",
-                         DPT_ACCESS, DPM_REFRESH_ACCESS_RULES, 0, NULL, NULL);
+                         0, sbus_req->sender->name, DPT_ACCESS, DPM_REFRESH_ACCESS_RULES,
+                         0, NULL, NULL);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;

diff --git a/src/providers/data_provider/dp_target_autofs.c b/src/providers/data_provider/dp_target_autofs.c
@@ -61,9 +61,9 @@ dp_autofs_get_map_send(TALLOC_CTX *mem_ctx,
 
     state->data->mapname = mapname;
 
-    subreq = dp_req_send(state, provider, NULL, "AutoFS", DPT_AUTOFS,
-                         DPM_AUTOFS_GET_MAP, dp_flags, state->data,
-                         NULL);
+    subreq = dp_req_send(state, provider, NULL, "AutoFS", cli_id,
+                         sbus_req->sender->name, DPT_AUTOFS, DPM_AUTOFS_GET_MAP,
+                         dp_flags, state->data, NULL);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;
@@ -144,7 +144,8 @@ dp_autofs_get_entry_send(TALLOC_CTX *mem_ctx,
     state->data->mapname = mapname;
     state->data->entryname = entryname;
 
-    subreq = dp_req_send(state, provider, NULL, "AutoFS", DPT_AUTOFS,
+    subreq = dp_req_send(state, provider, NULL, "AutoFS", cli_id,
+                         sbus_req->sender->name, DPT_AUTOFS,
                          DPM_AUTOFS_GET_ENTRY, dp_flags, state->data,
                          NULL);
     if (subreq == NULL) {
@@ -225,7 +226,8 @@ dp_autofs_enumerate_send(TALLOC_CTX *mem_ctx,
 
     state->data->mapname = mapname;
 
-    subreq = dp_req_send(state, provider, NULL, "AutoFS", DPT_AUTOFS,
+    subreq = dp_req_send(state, provider, NULL, "AutoFS", cli_id,
+                         sbus_req->sender->name, DPT_AUTOFS,
                          DPM_AUTOFS_ENUMERATE, dp_flags, state->data,
                          NULL);
     if (subreq == NULL) {

diff --git a/src/providers/data_provider/dp_target_hostid.c b/src/providers/data_provider/dp_target_hostid.c
@@ -65,9 +65,9 @@ dp_host_handler_send(TALLOC_CTX *mem_ctx,
     state->data->name = name;
     state->data->alias = SBUS_REQ_STRING(alias);
 
-    subreq = dp_req_send(state, provider, NULL, "HostID", DPT_HOSTID,
-                         DPM_HOSTID_HANDLER, dp_flags, state->data,
-                         &state->request_name);
+    subreq = dp_req_send(state, provider, NULL, "HostID", cli_id,
+                         sbus_req->sender->name, DPT_HOSTID, DPM_HOSTID_HANDLER,
+                         dp_flags, state->data, &state->request_name);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;

diff --git a/src/providers/data_provider/dp_target_id.c b/src/providers/data_provider/dp_target_id.c
@@ -518,7 +518,8 @@ dp_get_account_info_send(TALLOC_CTX *mem_ctx,
         }
     }
 
-    subreq = dp_req_send(state, provider, domain, state->request_name, DPT_ID,
+    subreq = dp_req_send(state, provider, domain, state->request_name,
+                         cli_id, sbus_req->sender->name, DPT_ID,
                          DPM_ACCOUNT_HANDLER, dp_flags, state->data,
                          &state->request_name);
     if (subreq == NULL) {
@@ -720,9 +721,9 @@ dp_get_account_domain_send(TALLOC_CTX *mem_ctx,
         goto done;
     }
 
-    subreq = dp_req_send(state, provider, NULL, "AccountDomain", DPT_ID,
-                         DPM_ACCT_DOMAIN_HANDLER, dp_flags, state->data,
-                         &state->request_name);
+    subreq = dp_req_send(state, provider, NULL, "AccountDomain", cli_id,
+                         sbus_req->sender->name, DPT_ID, DPM_ACCT_DOMAIN_HANDLER,
+                         dp_flags, state->data, &state->request_name);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;

diff --git a/src/providers/data_provider/dp_target_resolver.c b/src/providers/data_provider/dp_target_resolver.c
@@ -74,12 +74,14 @@ dp_resolver_handler_send(TALLOC_CTX *mem_ctx,
 
     switch (entry_type) {
     case BE_REQ_HOST:
-        subreq = dp_req_send(state, provider, NULL, "Resolver", DPT_RESOLVER,
-                             DPM_RESOLVER_HOSTS_HANDLER, dp_flags, state->data,
-                             &state->request_name);
+        subreq = dp_req_send(state, provider, NULL, "Resolver", cli_id,
+                             sbus_req->sender->name, DPT_RESOLVER,
+                             DPM_RESOLVER_HOSTS_HANDLER, dp_flags,
+                             state->data, &state->request_name);
         break;
     case BE_REQ_IP_NETWORK:
-        subreq = dp_req_send(state, provider, NULL, "Resolver", DPT_RESOLVER,
+        subreq = dp_req_send(state, provider, NULL, "Resolver", cli_id,
+                             sbus_req->sender->name, DPT_RESOLVER,
                              DPM_RESOLVER_IP_NETWORK_HANDLER, dp_flags,
                              state->data, &state->request_name);
         break;

diff --git a/src/providers/data_provider/dp_target_subdomains.c b/src/providers/data_provider/dp_target_subdomains.c
@@ -61,9 +61,9 @@ dp_subdomains_handler_send(TALLOC_CTX *mem_ctx,
 
     state->data->domain_hint = domain_hint;
 
-    subreq = dp_req_send(state, provider, NULL, "Subdomains", DPT_SUBDOMAINS,
-                         DPM_DOMAINS_HANDLER, 0, state->data,
-                         &state->request_name);
+    subreq = dp_req_send(state, provider, NULL, "Subdomains", 0,
+                         sbus_req->sender->name, DPT_SUBDOMAINS, DPM_DOMAINS_HANDLER,
+                         0, state->data, &state->request_name);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");
         ret = ENOMEM;

diff --git a/src/providers/data_provider/dp_target_sudo.c b/src/providers/data_provider/dp_target_sudo.c
@@ -144,8 +144,8 @@ dp_sudo_handler_send(TALLOC_CTX *mem_ctx,
 
     name = dp_sudo_get_name(state->data->type);
 
-    subreq = dp_req_send(state, provider, NULL, name, DPT_SUDO,
-                         DPM_SUDO_HANDLER, dp_flags, state->data,
+    subreq = dp_req_send(state, provider, NULL, name, 0, sbus_req->sender->name,
+                         DPT_SUDO, DPM_SUDO_HANDLER, dp_flags, state->data,
                          &state->request_name);
     if (subreq == NULL) {
         DEBUG(SSSDBG_CRIT_FAILURE, "Unable to create subrequest!\n");

diff --git a/src/providers/data_provider_be.c b/src/providers/data_provider_be.c
@@ -291,7 +291,7 @@ static errno_t be_check_online_request(struct be_ctx *be_ctx)
     reset_fo(be_ctx);
 
     req = dp_req_send(be_ctx, be_ctx->provider, NULL, "Online Check",
-                      DPT_ID, DPM_CHECK_ONLINE, 0, NULL, NULL);
+                      0, NULL, DPT_ID, DPM_CHECK_ONLINE, 0, NULL, NULL);
     if (req == NULL) {
         return ENOMEM;
     }

diff --git a/src/providers/ipa/ipa_subdomains_ext_groups.c b/src/providers/ipa/ipa_subdomains_ext_groups.c
@@ -1115,7 +1115,7 @@ struct tevent_req *ipa_ext_group_member_send(TALLOC_CTX *mem_ctx,
     }
 
     subreq = dp_req_send(state, ipa_ctx->sdap_id_ctx->be->provider,
-                         ar->domain, "External Member",
+                         ar->domain, "External Member", 0, NULL,
                          DPT_ID, DPM_ACCOUNT_HANDLER, 0, ar, NULL);
     if (subreq == NULL) {
         ret = ENOMEM;

diff --git a/src/providers/simple/simple_access_check.c b/src/providers/simple/simple_access_check.c
@@ -280,8 +280,8 @@ simple_resolve_group_send(TALLOC_CTX *mem_ctx,
     }
 
     subreq = dp_req_send(state, ctx->be_ctx->provider, ar->domain,
-                         "Simple Resolve Group", DPT_ID, DPM_ACCOUNT_HANDLER,
-                         0, ar, NULL);
+                         "Simple Resolve Group", 0, NULL,
+                         DPT_ID, DPM_ACCOUNT_HANDLER, 0, ar, NULL);
     if (!subreq) {
         ret = ENOMEM;
         goto done;

diff --git a/src/tests/cmocka/data_provider/test_dp_request.c b/src/tests/cmocka/data_provider/test_dp_request.c
@@ -89,6 +89,8 @@ bool __wrap_be_is_offline(struct be_ctx *ctx)
 #define NAME      "test_user"
 #define NAME2     "test_user2"
 #define REQ_NAME  "getpwuid"
+#define CID 1
+#define SENDER_NAME  "sssd.test"
 
 struct method_data
 {
@@ -225,22 +227,25 @@ static void test_get_name_by_uid(void **state)
     req_data3->uid = UID2; /* We are looking for user by UID */
 
     /* Send request #1 */
-    req = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME,
-                      DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data, &req_name);
+    req = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME, CID,
+                      SENDER_NAME, DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data,
+                      &req_name);
     assert_non_null(req);
     assert_string_equal(req_name, REQ_NAME" #0");
     talloc_zfree(req_name);
 
     /* Send request #2 */
-    req2 = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME,
-                       DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data2, &req_name);
+    req2 = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME, CID,
+                       SENDER_NAME, DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data2,
+                       &req_name);
     assert_non_null(req2);
     assert_string_equal(req_name, REQ_NAME" #1");
     talloc_zfree(req_name);
 
     /* Send request #3 */
-    req3 = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME,
-                       DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data3, &req_name);
+    req3 = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME, CID,
+                       SENDER_NAME, DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data3,
+                       &req_name);
     assert_non_null(req3);
     assert_string_equal(req_name, REQ_NAME" #2");
     talloc_zfree(req_name);
@@ -297,8 +302,8 @@ static void test_type_mismatch(void **state)
     req_data->uid = UID; /* We are looking for user by UID */
 
     /* Send request #1 */
-    req = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME,
-                      DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data, &req_name);
+    req = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME, CID,
+                      SENDER_NAME, DPT_ID, DPM_ACCOUNT_HANDLER, 0, req_data, &req_name);
     assert_non_null(req);
     assert_string_equal(req_name, REQ_NAME" #0");
     talloc_zfree(req_name);
@@ -343,7 +348,7 @@ static void test_nonexist_dom(void **state)
     /* Send request #1 */
     req = dp_req_send(test_ctx, test_ctx->provider,
                       "non-existing domain name",
-                      REQ_NAME,
+                      REQ_NAME, CID, SENDER_NAME,
                       DPT_ID, DPM_ACCOUNT_HANDLER,
                       0,
                       req_data, NULL);
@@ -391,6 +396,7 @@ static void test_fast_reply(void **state)
 
     /* Send request #1 */
     req = dp_req_send(test_ctx, test_ctx->provider, NULL, REQ_NAME,
+                      CID, SENDER_NAME,
                       DPT_ID, DPM_ACCOUNT_HANDLER,
                       DP_FAST_REPLY, /* FAST REPLY, don't check online! */
                       req_data, NULL);