URL: https://github.com/SSSD/sssd/pull/5863 Author: justin-stephenson Title: #5863: Responder and Child process tevent chain id improvements Action: synchronized
To pull the PR as Git branch: git remote add ghsssd https://github.com/SSSD/sssd git fetch ghsssd pull/5863/head:pr5863 git checkout pr5863
From fc2a3aac18661ea7fe43e7adf477e06ae2cf988e Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 15:41:23 +0000 Subject: [PATCH 01/16] util: Split chain ID tevent functions Commonly used chain ID functions sss_chain_id_get() and sss_chain_id_set() will be isolated from requiring tevent when building sources. --- Makefile.am | 2 + src/providers/data_provider_be.c | 1 + src/util/sss_chain_id.c | 130 +---------------------------- src/util/sss_chain_id.h | 7 +- src/util/sss_chain_id_tevent.c | 138 +++++++++++++++++++++++++++++++ src/util/sss_chain_id_tevent.h | 29 +++++++ 6 files changed, 175 insertions(+), 132 deletions(-) create mode 100644 src/util/sss_chain_id_tevent.c create mode 100644 src/util/sss_chain_id_tevent.h diff --git a/Makefile.am b/Makefile.am index 5fed0d0973..54a681bc53 100644 --- a/Makefile.am +++ b/Makefile.am @@ -685,6 +685,7 @@ dist_noinst_HEADERS = \ src/util/session_recording.h \ src/util/strtonum.h \ src/util/sss_cli_cmd.h \ + src/util/sss_chain_id_tevent.h \ src/util/sss_chain_id.h \ src/util/sss_ptr_hash.h \ src/util/sss_ptr_list.h \ @@ -1266,6 +1267,7 @@ libsss_util_la_SOURCES = \ src/util/files.c \ src/util/selinux.c \ src/util/sss_regexp.c \ + src/util/sss_chain_id_tevent.c \ src/util/sss_chain_id.c \ src/util/nss_dl_load.c \ src/util/nss_dl_load_extra.c \ diff --git a/src/providers/data_provider_be.c b/src/providers/data_provider_be.c index 9d63b448ea..c632ec9461 100644 --- a/src/providers/data_provider_be.c +++ b/src/providers/data_provider_be.c @@ -47,6 +47,7 @@ #include "util/child_common.h" #include "resolv/async_resolv.h" #include "sss_iface/sss_iface_async.h" +#include "util/sss_chain_id_tevent.h" #include "util/sss_chain_id.h" #define ONLINE_CB_RETRY 3 diff --git a/src/util/sss_chain_id.c b/src/util/sss_chain_id.c index f892e2eb78..db312698ab 100644 --- a/src/util/sss_chain_id.c +++ b/src/util/sss_chain_id.c @@ -18,115 +18,8 @@ along with this program. If not, see <http://www.gnu.org/licenses/>. */ -#include "config.h" - -#include <tevent.h> - -#ifdef BUILD_CHAIN_ID -extern uint64_t debug_chain_id; - -static void sss_chain_id_trace_fde(struct tevent_fd *fde, - enum tevent_event_trace_point point, - void *private_data) -{ - switch (point) { - case TEVENT_EVENT_TRACE_ATTACH: - /* Assign the current chain id when the event is created. */ - tevent_fd_set_tag(fde, debug_chain_id); - break; - case TEVENT_EVENT_TRACE_BEFORE_HANDLER: - /* Set the chain id when a handler is being called. */ - debug_chain_id = tevent_fd_get_tag(fde); - break; - default: - /* Do nothing. */ - break; - } -} - -static void sss_chain_id_trace_signal(struct tevent_signal *se, - enum tevent_event_trace_point point, - void *private_data) -{ - switch (point) { - case TEVENT_EVENT_TRACE_ATTACH: - /* Assign the current chain id when the event is created. */ - tevent_signal_set_tag(se, debug_chain_id); - break; - case TEVENT_EVENT_TRACE_BEFORE_HANDLER: - /* Set the chain id when a handler is being called. */ - debug_chain_id = tevent_signal_get_tag(se); - break; - default: - /* Do nothing. */ - break; - } -} - -static void sss_chain_id_trace_timer(struct tevent_timer *timer, - enum tevent_event_trace_point point, - void *private_data) -{ - switch (point) { - case TEVENT_EVENT_TRACE_ATTACH: - /* Assign the current chain id when the event is created. */ - tevent_timer_set_tag(timer, debug_chain_id); - break; - case TEVENT_EVENT_TRACE_BEFORE_HANDLER: - /* Set the chain id when a handler is being called. */ - debug_chain_id = tevent_timer_get_tag(timer); - break; - default: - /* Do nothing. */ - break; - } -} - -static void sss_chain_id_trace_immediate(struct tevent_immediate *im, - enum tevent_event_trace_point point, - void *private_data) -{ - switch (point) { - case TEVENT_EVENT_TRACE_ATTACH: - /* Assign the current chain id when the event is created. */ - tevent_immediate_set_tag(im, debug_chain_id); - break; - case TEVENT_EVENT_TRACE_BEFORE_HANDLER: - /* Set the chain id when a handler is being called. */ - debug_chain_id = tevent_immediate_get_tag(im); - break; - default: - /* Do nothing. */ - break; - } -} - -static void sss_chain_id_trace_loop(enum tevent_trace_point point, - void *private_data) -{ - switch (point) { - case TEVENT_TRACE_AFTER_LOOP_ONCE: - /* Reset chain id when we got back to the loop. An event handler - * that set chain id was fired. This tracepoint represents a place - * after the event handler was finished, we need to restore chain - * id to 0 (out of request). - */ - debug_chain_id = 0; - break; - default: - /* Do nothing. */ - break; - } -} - -void sss_chain_id_setup(struct tevent_context *ev) -{ - tevent_set_trace_callback(ev, sss_chain_id_trace_loop, NULL); - tevent_set_trace_fd_callback(ev, sss_chain_id_trace_fde, NULL); - tevent_set_trace_signal_callback(ev, sss_chain_id_trace_signal, NULL); - tevent_set_trace_timer_callback(ev, sss_chain_id_trace_timer, NULL); - tevent_set_trace_immediate_callback(ev, sss_chain_id_trace_immediate, NULL); -} +#include <stdint.h> +#include "util/sss_chain_id.h" uint64_t sss_chain_id_set(uint64_t id) { @@ -139,22 +32,3 @@ uint64_t sss_chain_id_get(void) { return debug_chain_id; } - -#else /* BUILD_CHAIN_ID not defined */ - -void sss_chain_id_setup(struct tevent_context *ev) -{ - return; -} - -uint64_t sss_chain_id_set(uint64_t id) -{ - return 0; -} - -uint64_t sss_chain_id_get(void) -{ - return 0; -} - -#endif /* BUILD_CHAIN_ID */ diff --git a/src/util/sss_chain_id.h b/src/util/sss_chain_id.h index b29fad0cb1..e15cc5b889 100644 --- a/src/util/sss_chain_id.h +++ b/src/util/sss_chain_id.h @@ -1,6 +1,6 @@ /* Authors: - Pavel Březina <pbrez...@redhat.com> + Justin Stephenson <jstep...@redhat.com> Copyright (C) 2021 Red Hat @@ -21,10 +21,9 @@ #ifndef _SSS_CHAIN_ID_ #define _SSS_CHAIN_ID_ -#include <tevent.h> +#include <stdint.h> -/* Setup chain id tracking on tevent context. */ -void sss_chain_id_setup(struct tevent_context *ev); +extern uint64_t debug_chain_id; /* Explicitly set new chain id. The old id is returned. */ uint64_t sss_chain_id_set(uint64_t id); diff --git a/src/util/sss_chain_id_tevent.c b/src/util/sss_chain_id_tevent.c new file mode 100644 index 0000000000..a68607da65 --- /dev/null +++ b/src/util/sss_chain_id_tevent.c @@ -0,0 +1,138 @@ +/* + Authors: + Pavel Březina <pbrez...@redhat.com> + + Copyright (C) 2021 Red Hat + + This program is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 3 of the License, or + (at your option) any later version. + + This program is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with this program. If not, see <http://www.gnu.org/licenses/>. +*/ + +#include "config.h" +#include "util/sss_chain_id.h" + +#include <tevent.h> + +#ifdef BUILD_CHAIN_ID + +static void sss_chain_id_trace_fde(struct tevent_fd *fde, + enum tevent_event_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_EVENT_TRACE_ATTACH: + /* Assign the current chain id when the event is created. */ + tevent_fd_set_tag(fde, debug_chain_id); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the chain id when a handler is being called. */ + debug_chain_id = tevent_fd_get_tag(fde); + break; + default: + /* Do nothing. */ + break; + } +} + +static void sss_chain_id_trace_signal(struct tevent_signal *se, + enum tevent_event_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_EVENT_TRACE_ATTACH: + /* Assign the current chain id when the event is created. */ + tevent_signal_set_tag(se, debug_chain_id); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the chain id when a handler is being called. */ + debug_chain_id = tevent_signal_get_tag(se); + break; + default: + /* Do nothing. */ + break; + } +} + +static void sss_chain_id_trace_timer(struct tevent_timer *timer, + enum tevent_event_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_EVENT_TRACE_ATTACH: + /* Assign the current chain id when the event is created. */ + tevent_timer_set_tag(timer, debug_chain_id); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the chain id when a handler is being called. */ + debug_chain_id = tevent_timer_get_tag(timer); + break; + default: + /* Do nothing. */ + break; + } +} + +static void sss_chain_id_trace_immediate(struct tevent_immediate *im, + enum tevent_event_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_EVENT_TRACE_ATTACH: + /* Assign the current chain id when the event is created. */ + tevent_immediate_set_tag(im, debug_chain_id); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the chain id when a handler is being called. */ + debug_chain_id = tevent_immediate_get_tag(im); + break; + default: + /* Do nothing. */ + break; + } +} + +static void sss_chain_id_trace_loop(enum tevent_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_TRACE_AFTER_LOOP_ONCE: + /* Reset chain id when we got back to the loop. An event handler + * that set chain id was fired. This tracepoint represents a place + * after the event handler was finished, we need to restore chain + * id to 0 (out of request). + */ + debug_chain_id = 0; + break; + default: + /* Do nothing. */ + break; + } +} + +void sss_chain_id_setup(struct tevent_context *ev) +{ + tevent_set_trace_callback(ev, sss_chain_id_trace_loop, NULL); + tevent_set_trace_fd_callback(ev, sss_chain_id_trace_fde, NULL); + tevent_set_trace_signal_callback(ev, sss_chain_id_trace_signal, NULL); + tevent_set_trace_timer_callback(ev, sss_chain_id_trace_timer, NULL); + tevent_set_trace_immediate_callback(ev, sss_chain_id_trace_immediate, NULL); +} + +#else /* BUILD_CHAIN_ID not defined */ + +void sss_chain_id_setup(struct tevent_context *ev) +{ + return; +} + +#endif /* BUILD_CHAIN_ID */ diff --git a/src/util/sss_chain_id_tevent.h b/src/util/sss_chain_id_tevent.h new file mode 100644 index 0000000000..547d271641 --- /dev/null +++ b/src/util/sss_chain_id_tevent.h @@ -0,0 +1,29 @@ +/* + Authors: + Pavel Březina <pbrez...@redhat.com> + + Copyright (C) 2021 Red Hat + + This program is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 3 of the License, or + (at your option) any later version. + + This program is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with this program. If not, see <http://www.gnu.org/licenses/>. +*/ + +#ifndef _SSS_CHAIN_ID_TEVENT_ +#define _SSS_CHAIN_ID_TEVENT_ + +#include <tevent.h> + +/* Setup chain id tracking on tevent context. */ +void sss_chain_id_setup(struct tevent_context *ev); + +#endif /* _SSS_CHAIN_ID_TEVENT_ */ From 7faefa1ce4371f2963b057758c7d10ef20a95304 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Thu, 28 Oct 2021 13:48:24 +0000 Subject: [PATCH 02/16] RESPONDER: Remove extraneous client ID logging Prevent duplicate ID logging. ID will be logged in separate commit with added tevent chain ID support in responders. --- src/responder/common/responder_common.c | 2 +- src/responder/nss/nss_get_object.c | 5 ++--- src/responder/pam/pamsrv_cmd.c | 4 ++-- src/responder/pam/pamsrv_dp.c | 8 +++---- src/util/sss_pam_data.c | 28 ++++++++++++------------- 5 files changed, 21 insertions(+), 26 deletions(-) diff --git a/src/responder/common/responder_common.c b/src/responder/common/responder_common.c index 913dbcd800..d0c580f0d9 100644 --- a/src/responder/common/responder_common.c +++ b/src/responder/common/responder_common.c @@ -639,7 +639,7 @@ static void accept_fd_handler(struct tevent_context *ev, rctx->client_id_num++; DEBUG(SSSDBG_TRACE_FUNC, - "Client [CID #%u][cmd %s][uid %u][%p][%d] connected%s!\n", + "[CID#%u] Client [cmd %s][uid %u][%p][%d] connected%s!\n", rctx->client_id_num, cctx->cmd_line, cli_creds_get_uid(cctx->creds), cctx, cctx->cfd, accept_ctx->is_private ? " to privileged pipe" : ""); diff --git a/src/responder/nss/nss_get_object.c b/src/responder/nss/nss_get_object.c index 9d53f070c9..30d8cb7e15 100644 --- a/src/responder/nss/nss_get_object.c +++ b/src/responder/nss/nss_get_object.c @@ -309,9 +309,8 @@ nss_get_object_send(TALLOC_CTX *mem_ctx, goto done; } - DEBUG(SSSDBG_TRACE_FUNC, "Client [%p][%d][CID #%u]: sent cache request #%u\n", - cli_ctx, cli_ctx->cfd, cli_ctx->rctx->client_id_num, - cache_req_get_reqid(subreq)); + DEBUG(SSSDBG_TRACE_FUNC, "Client [%p][%d]: sent cache request #%u\n", + cli_ctx, cli_ctx->cfd, cache_req_get_reqid(subreq)); tevent_req_set_callback(subreq, nss_get_object_done, req); diff --git a/src/responder/pam/pamsrv_cmd.c b/src/responder/pam/pamsrv_cmd.c index 20c332b1a4..580ccd3839 100644 --- a/src/responder/pam/pamsrv_cmd.c +++ b/src/responder/pam/pamsrv_cmd.c @@ -1154,8 +1154,8 @@ static void pam_reply(struct pam_auth_req *preq) } done: - DEBUG(SSSDBG_FUNC_DATA, "Returning [%d]: %s to the client [CID #%u]\n", - pd->pam_status, pam_strerror(NULL, pd->pam_status), pd->client_id_num); + DEBUG(SSSDBG_FUNC_DATA, "Returning [%d]: %s to the client\n", + pd->pam_status, pam_strerror(NULL, pd->pam_status)); sss_cmd_done(cctx, preq); } diff --git a/src/responder/pam/pamsrv_dp.c b/src/responder/pam/pamsrv_dp.c index b3900e17e9..881352e54c 100644 --- a/src/responder/pam/pamsrv_dp.c +++ b/src/responder/pam/pamsrv_dp.c @@ -47,8 +47,7 @@ pam_dp_send_req(struct pam_auth_req *preq) return EIO; } - DEBUG(SSSDBG_CONF_SETTINGS, "Sending request [CID #%u] with the following data:\n", - preq->client_id_num); + DEBUG(SSSDBG_CONF_SETTINGS, "Sending request with the following data:\n"); DEBUG_PAM_DATA(SSSDBG_CONF_SETTINGS, preq->pd); subreq = sbus_call_dp_dp_pamHandler_send(preq, be_conn->conn, @@ -85,11 +84,10 @@ pam_dp_send_req_done(struct tevent_req *subreq) preq->pd->pam_status = pam_response->pam_status; preq->pd->account_locked = pam_response->account_locked; - DEBUG(SSSDBG_FUNC_DATA, "received: [%d (%s)][%s][CID #%u]\n", + DEBUG(SSSDBG_FUNC_DATA, "received: [%d (%s)][%s]\n", pam_response->pam_status, pam_strerror(NULL, pam_response->pam_status), - preq->pd->domain, - preq->pd->client_id_num); + preq->pd->domain); for (resp = pam_response->resp_list; resp != NULL; resp = resp->next) { talloc_steal(preq->pd, resp); diff --git a/src/util/sss_pam_data.c b/src/util/sss_pam_data.c index ebea11ea59..3eda598c68 100644 --- a/src/util/sss_pam_data.c +++ b/src/util/sss_pam_data.c @@ -165,25 +165,23 @@ errno_t copy_pam_data(TALLOC_CTX *mem_ctx, struct pam_data *src, void pam_print_data(int l, struct pam_data *pd) { - DEBUG(l, "[CID #%u] command: %s\n", pd->client_id_num, sss_cmd2str(pd->cmd)); - DEBUG(l, "[CID #%u] domain: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->domain)); - DEBUG(l, "[CID #%u] user: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->user)); - DEBUG(l, "[CID #%u] service: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->service)); - DEBUG(l, "[CID #%u] tty: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->tty)); - DEBUG(l, "[CID #%u] ruser: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->ruser)); - DEBUG(l, "[CID #%u] rhost: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->rhost)); - DEBUG(l, "[CID #%u] authtok type: %d (%s)\n", - pd->client_id_num, + DEBUG(l, "command: %s\n", sss_cmd2str(pd->cmd)); + DEBUG(l, "domain: %s\n", PAM_SAFE_ITEM(pd->domain)); + DEBUG(l, "user: %s\n", PAM_SAFE_ITEM(pd->user)); + DEBUG(l, "service: %s\n", PAM_SAFE_ITEM(pd->service)); + DEBUG(l, "tty: %s\n", PAM_SAFE_ITEM(pd->tty)); + DEBUG(l, "ruser: %s\n", PAM_SAFE_ITEM(pd->ruser)); + DEBUG(l, "rhost: %s\n", PAM_SAFE_ITEM(pd->rhost)); + DEBUG(l, "authtok type: %d (%s)\n", sss_authtok_get_type(pd->authtok), sss_authtok_type_to_str(sss_authtok_get_type(pd->authtok))); - DEBUG(l, "[CID #%u] newauthtok type: %d (%s)\n", - pd->client_id_num, + DEBUG(l, "newauthtok type: %d (%s)\n", sss_authtok_get_type(pd->newauthtok), sss_authtok_type_to_str(sss_authtok_get_type(pd->newauthtok))); - DEBUG(l, "[CID #%u] priv: %d\n", pd->client_id_num, pd->priv); - DEBUG(l, "[CID #%u] cli_pid: %d\n", pd->client_id_num, pd->cli_pid); - DEBUG(l, "[CID #%u] logon name: %s\n", pd->client_id_num, PAM_SAFE_ITEM(pd->logon_name)); - DEBUG(l, "[CID #%u] flags: %d\n", pd->client_id_num, pd->cli_flags); + DEBUG(l, "priv: %d\n", pd->priv); + DEBUG(l, "cli_pid: %d\n", pd->cli_pid); + DEBUG(l, "logon name: %s\n", PAM_SAFE_ITEM(pd->logon_name)); + DEBUG(l, "flags: %d\n", pd->cli_flags); } int pam_add_response(struct pam_data *pd, enum response_type type, From 2e10babe94420940313a7a11ed699208a1a12090 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Mon, 13 Dec 2021 14:13:26 -0500 Subject: [PATCH 03/16] sbus: Remember outgoing request chain ID --- src/sbus/request/sbus_request.c | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/src/sbus/request/sbus_request.c b/src/sbus/request/sbus_request.c index 99e21509f2..8d49259eae 100644 --- a/src/sbus/request/sbus_request.c +++ b/src/sbus/request/sbus_request.c @@ -25,6 +25,7 @@ #include "util/util.h" #include "util/dlinklist.h" +#include "util/sss_chain_id.h" #include "sbus/sbus_request.h" #include "sbus/sbus_private.h" @@ -575,6 +576,7 @@ struct sbus_outgoing_request_state { const char *key; struct sbus_connection *conn; DBusMessage *reply; + uint64_t chain_id; }; static errno_t @@ -620,6 +622,14 @@ sbus_outgoing_request_send(TALLOC_CTX *mem_ctx, state->conn = conn; + /* + * The message is sent over top level dbus tevent code. This means that + * the chain id information is lost and is not restored when we get reply + * from dbus. Therefore we need to remember it and restore it manually + * when this request is done. + */ + state->chain_id = sss_chain_id_get(); + if (key != NULL) { state->key = talloc_strdup(state, key); if (state->key == NULL) { @@ -676,6 +686,8 @@ static void sbus_outgoing_request_done(struct tevent_req *subreq) req = tevent_req_callback_data(subreq, struct tevent_req); state = tevent_req_data(req, struct sbus_outgoing_request_state); + sss_chain_id_set(state->chain_id); + ret = sbus_message_recv(state, subreq, &state->reply); talloc_zfree(subreq); From 3ca9439292a70e9ba74972fa608c4f2352068c65 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Mon, 13 Dec 2021 14:10:45 -0500 Subject: [PATCH 04/16] RESPONDER: Support chain ID logging --- src/responder/common/responder.h | 1 + src/responder/common/responder_common.c | 12 +++++++++++- 2 files changed, 12 insertions(+), 1 deletion(-) diff --git a/src/responder/common/responder.h b/src/responder/common/responder.h index 90575b89e7..5cb79e3e63 100644 --- a/src/responder/common/responder.h +++ b/src/responder/common/responder.h @@ -165,6 +165,7 @@ struct cli_ctx { struct cli_creds *creds; char *cmd_line; + uint64_t old_chain_id; void *protocol_ctx; void *state_ctx; diff --git a/src/responder/common/responder_common.c b/src/responder/common/responder_common.c index d0c580f0d9..2b95faabe3 100644 --- a/src/responder/common/responder_common.c +++ b/src/responder/common/responder_common.c @@ -42,6 +42,8 @@ #include "providers/data_provider.h" #include "util/util_creds.h" #include "sss_iface/sss_iface_async.h" +#include "util/sss_chain_id_tevent.h" +#include "util/sss_chain_id.h" #ifdef HAVE_SYSTEMD #include <systemd/sd-daemon.h> @@ -85,6 +87,8 @@ static void client_close_fn(struct tevent_context *ev, "Failed to close fd [%d]: [%s]\n", ctx->cfd, strerror(ret)); } + /* Restore the original chain id */ + sss_chain_id_set(ctx->old_chain_id); DEBUG(SSSDBG_TRACE_INTERNAL, "Terminated client [%p][%d]\n", @@ -521,6 +525,8 @@ static void accept_fd_handler(struct tevent_context *ev, int ret; int fd = accept_ctx->is_private ? rctx->priv_lfd : rctx->lfd; + rctx->client_id_num++; + if (accept_ctx->is_private) { ret = stat(rctx->priv_sock_name, &stat_buf); if (ret == -1) { @@ -637,7 +643,6 @@ static void accept_fd_handler(struct tevent_context *ev, /* Non-fatal, continue */ } - rctx->client_id_num++; DEBUG(SSSDBG_TRACE_FUNC, "[CID#%u] Client [cmd %s][uid %u][%p][%d] connected%s!\n", rctx->client_id_num, cctx->cmd_line, cli_creds_get_uid(cctx->creds), @@ -1099,6 +1104,9 @@ void sss_client_fd_handler(void *ptr, /* Non-fatal, continue */ } + /* Set the chain id */ + cctx->old_chain_id = sss_chain_id_set(cctx->rctx->client_id_num); + if (flags & TEVENT_FD_READ) { recv_fn(cctx); return; @@ -1311,6 +1319,8 @@ int sss_process_init(TALLOC_CTX *mem_ctx, goto fail; } + sss_chain_id_setup(rctx->ev); + /* Ensure that the client timeout is at least ten seconds */ if (rctx->client_idle_timeout < 10) { rctx->client_idle_timeout = 10; From 3d754af39526b2b21366beaf370f0ce418bbc59a Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Mon, 13 Dec 2021 13:32:55 -0500 Subject: [PATCH 05/16] chain_id: Add support for custom debug format --- src/util/debug.c | 13 ++++++++----- src/util/sss_chain_id.c | 5 +++++ src/util/sss_chain_id.h | 4 ++++ src/util/sss_chain_id_tevent.c | 4 +++- src/util/sss_chain_id_tevent.h | 3 ++- src/util/util.h | 3 +++ 6 files changed, 25 insertions(+), 7 deletions(-) diff --git a/src/util/debug.c b/src/util/debug.c index 9531237183..b54eca7cee 100644 --- a/src/util/debug.c +++ b/src/util/debug.c @@ -36,8 +36,6 @@ #include "util/util.h" -#define DEBUG_CHAIN_ID_FMT "[RID#%lu] " - /* from debug_backtrace.h */ void sss_debug_backtrace_init(void); void sss_debug_backtrace_vprintf(int level, const char *format, va_list ap); @@ -53,6 +51,7 @@ enum sss_logger_t sss_logger = STDERR_LOGGER; const char *debug_log_file = "sssd"; FILE *_sss_debug_file; uint64_t debug_chain_id; +const char *debug_chain_id_fmt; const char *sss_logger_str[] = { [STDERR_LOGGER] = "stderr", @@ -276,6 +275,7 @@ void sss_vdebug_fn(const char *file, time_t t; #ifdef WITH_JOURNALD + char combined_fmt[32]; char chain_id_fmt_fixed[256]; char *chain_id_fmt_dyn = NULL; char *result_fmt; @@ -293,14 +293,17 @@ void sss_vdebug_fn(const char *file, */ va_copy(ap_fallback, ap); if (debug_chain_id > 0) { + strncpy(combined_fmt, debug_chain_id_fmt, sizeof(combined_fmt) - 1); + strcat(combined_fmt, "%s"); + result_fmt = chain_id_fmt_fixed; ret = snprintf(chain_id_fmt_fixed, sizeof(chain_id_fmt_fixed), - DEBUG_CHAIN_ID_FMT"%s", debug_chain_id, format); + combined_fmt, debug_chain_id, format); if (ret < 0) { va_end(ap_fallback); return; } else if (ret >= sizeof(chain_id_fmt_fixed)) { - ret = asprintf(&chain_id_fmt_dyn, DEBUG_CHAIN_ID_FMT"%s", + ret = asprintf(&chain_id_fmt_dyn, combined_fmt, debug_chain_id, format); if (ret < 0) { va_end(ap_fallback); @@ -351,7 +354,7 @@ void sss_vdebug_fn(const char *file, debug_prg_name, function, level); if (debug_chain_id > 0) { - sss_debug_backtrace_printf(level, DEBUG_CHAIN_ID_FMT, debug_chain_id); + sss_debug_backtrace_printf(level, debug_chain_id_fmt, debug_chain_id); } sss_debug_backtrace_vprintf(level, format, ap); diff --git a/src/util/sss_chain_id.c b/src/util/sss_chain_id.c index db312698ab..980225dbaa 100644 --- a/src/util/sss_chain_id.c +++ b/src/util/sss_chain_id.c @@ -21,6 +21,11 @@ #include <stdint.h> #include "util/sss_chain_id.h" +void sss_chain_id_set_format(const char *fmt) +{ + debug_chain_id_fmt = fmt; +} + uint64_t sss_chain_id_set(uint64_t id) { uint64_t old_id = debug_chain_id; diff --git a/src/util/sss_chain_id.h b/src/util/sss_chain_id.h index e15cc5b889..752283837c 100644 --- a/src/util/sss_chain_id.h +++ b/src/util/sss_chain_id.h @@ -24,6 +24,7 @@ #include <stdint.h> extern uint64_t debug_chain_id; +extern const char *debug_chain_id_fmt; /* Explicitly set new chain id. The old id is returned. */ uint64_t sss_chain_id_set(uint64_t id); @@ -31,4 +32,7 @@ uint64_t sss_chain_id_set(uint64_t id); /* Get the current chain id. */ uint64_t sss_chain_id_get(void); +/* Set new debug chain id logging format. */ +void sss_chain_id_set_format(const char *fmt); + #endif /* _SSS_CHAIN_ID_ */ diff --git a/src/util/sss_chain_id_tevent.c b/src/util/sss_chain_id_tevent.c index a68607da65..5904c20136 100644 --- a/src/util/sss_chain_id_tevent.c +++ b/src/util/sss_chain_id_tevent.c @@ -119,13 +119,15 @@ static void sss_chain_id_trace_loop(enum tevent_trace_point point, } } -void sss_chain_id_setup(struct tevent_context *ev) +void sss_chain_id_setup(struct tevent_context *ev, const char *fmt) { tevent_set_trace_callback(ev, sss_chain_id_trace_loop, NULL); tevent_set_trace_fd_callback(ev, sss_chain_id_trace_fde, NULL); tevent_set_trace_signal_callback(ev, sss_chain_id_trace_signal, NULL); tevent_set_trace_timer_callback(ev, sss_chain_id_trace_timer, NULL); tevent_set_trace_immediate_callback(ev, sss_chain_id_trace_immediate, NULL); + + debug_chain_id_fmt = fmt; } #else /* BUILD_CHAIN_ID not defined */ diff --git a/src/util/sss_chain_id_tevent.h b/src/util/sss_chain_id_tevent.h index 547d271641..29a37d6b54 100644 --- a/src/util/sss_chain_id_tevent.h +++ b/src/util/sss_chain_id_tevent.h @@ -24,6 +24,7 @@ #include <tevent.h> /* Setup chain id tracking on tevent context. */ -void sss_chain_id_setup(struct tevent_context *ev); +void sss_chain_id_setup(struct tevent_context *ev, + const char *fmt); #endif /* _SSS_CHAIN_ID_TEVENT_ */ diff --git a/src/util/util.h b/src/util/util.h index 6dfd2540cc..0102f94570 100644 --- a/src/util/util.h +++ b/src/util/util.h @@ -182,6 +182,9 @@ void sss_log(int priority, const char *format, ...) SSS_ATTRIBUTE_PRINTF(2, 3); void sss_log_ext(int priority, int facility, const char *format, ...) SSS_ATTRIBUTE_PRINTF(3, 4); /* from server.c */ +#define DEBUG_CHAIN_ID_FMT_RID "[RID#%lu] " +#define DEBUG_CHAIN_ID_FMT_CID "[CID#%lu] " + struct main_context { struct tevent_context *event_ctx; struct confdb_ctx *confdb_ctx; From 981be55d8e2cfb80f50e9d0eb9b892ab22354288 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Mon, 13 Dec 2021 13:33:42 -0500 Subject: [PATCH 06/16] DEBUG: Log chain ID messages with [CID#X] tag Inform the debug module when a responder process is sending debug log messages, use the [CID #] tag in responder code and [RID #] tag in backend/child process code. --- src/monitor/monitor.c | 2 +- src/p11_child/p11_child_common.c | 2 ++ src/providers/ad/ad_gpo_child.c | 2 ++ src/providers/data_provider_be.c | 6 +----- src/providers/ipa/selinux_child.c | 3 +++ src/providers/krb5/krb5_child.c | 3 +++ src/providers/proxy/proxy_child.c | 5 ++++- src/responder/autofs/autofssrv.c | 2 +- src/responder/common/responder_common.c | 2 -- src/responder/ifp/ifpsrv.c | 2 +- src/responder/kcm/kcm.c | 2 +- src/responder/nss/nsssrv.c | 2 +- src/responder/pac/pacsrv.c | 2 +- src/responder/pam/pamsrv.c | 2 +- src/responder/ssh/sshsrv.c | 2 +- src/responder/sudo/sudosrv.c | 2 +- src/tests/cwrap/test_server.c | 6 +++--- src/util/server.c | 10 +++++++++- src/util/util.h | 3 ++- 19 files changed, 38 insertions(+), 22 deletions(-) diff --git a/src/monitor/monitor.c b/src/monitor/monitor.c index 55cb0838aa..b86056bc6c 100644 --- a/src/monitor/monitor.c +++ b/src/monitor/monitor.c @@ -2550,7 +2550,7 @@ int main(int argc, const char *argv[]) ret = close(STDIN_FILENO); if (ret != EOK) return 6; - ret = server_setup(SSSD_MONITOR_NAME, flags, 0, 0, + ret = server_setup(SSSD_MONITOR_NAME, false, flags, 0, 0, monitor->conf_path, &main_ctx); if (ret != EOK) return 2; diff --git a/src/p11_child/p11_child_common.c b/src/p11_child/p11_child_common.c index 7c8259479d..f691ab6363 100644 --- a/src/p11_child/p11_child_common.c +++ b/src/p11_child/p11_child_common.c @@ -313,6 +313,8 @@ int main(int argc, const char *argv[]) } } + sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_CID); + DEBUG_INIT(debug_level, opt_logger); DEBUG(SSSDBG_TRACE_FUNC, "p11_child started.\n"); diff --git a/src/providers/ad/ad_gpo_child.c b/src/providers/ad/ad_gpo_child.c index 8a3a87195b..2e5c5c3f69 100644 --- a/src/providers/ad/ad_gpo_child.c +++ b/src/providers/ad/ad_gpo_child.c @@ -775,6 +775,8 @@ main(int argc, const char *argv[]) } } + sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_RID); + DEBUG_INIT(debug_level, opt_logger); DEBUG(SSSDBG_TRACE_FUNC, "gpo_child started.\n"); diff --git a/src/providers/data_provider_be.c b/src/providers/data_provider_be.c index c632ec9461..5ceff04c9f 100644 --- a/src/providers/data_provider_be.c +++ b/src/providers/data_provider_be.c @@ -47,8 +47,6 @@ #include "util/child_common.h" #include "resolv/async_resolv.h" #include "sss_iface/sss_iface_async.h" -#include "util/sss_chain_id_tevent.h" -#include "util/sss_chain_id.h" #define ONLINE_CB_RETRY 3 #define ONLINE_CB_RETRY_MAX_DELAY 4 @@ -772,14 +770,12 @@ int main(int argc, const char *argv[]) confdb_path = talloc_asprintf(NULL, CONFDB_DOMAIN_PATH_TMPL, be_domain); if (!confdb_path) return 2; - ret = server_setup(srv_name, 0, 0, 0, confdb_path, &main_ctx); + ret = server_setup(srv_name, false, 0, 0, 0, confdb_path, &main_ctx); if (ret != EOK) { DEBUG(SSSDBG_FATAL_FAILURE, "Could not set up mainloop [%d]\n", ret); return 2; } - sss_chain_id_setup(main_ctx->event_ctx); - ret = setenv(SSS_DOM_ENV, be_domain, 1); if (ret != 0) { DEBUG(SSSDBG_MINOR_FAILURE, "Setting "SSS_DOM_ENV" failed, journald " diff --git a/src/providers/ipa/selinux_child.c b/src/providers/ipa/selinux_child.c index d9b6e15c93..db8ece5719 100644 --- a/src/providers/ipa/selinux_child.c +++ b/src/providers/ipa/selinux_child.c @@ -258,6 +258,9 @@ int main(int argc, const char *argv[]) } } + sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_RID); + sss_chain_id_set(chain_id); + DEBUG_INIT(debug_level, opt_logger); DEBUG(SSSDBG_TRACE_FUNC, "selinux_child started.\n"); diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c index 594c86bf61..fdc111fd46 100644 --- a/src/providers/krb5/krb5_child.c +++ b/src/providers/krb5/krb5_child.c @@ -3386,6 +3386,9 @@ int main(int argc, const char *argv[]) } } + sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_RID); + sss_chain_id_set(chain_id); + DEBUG_INIT(debug_level, opt_logger); DEBUG(SSSDBG_TRACE_FUNC, "krb5_child started.\n"); diff --git a/src/providers/proxy/proxy_child.c b/src/providers/proxy/proxy_child.c index d9e3d0d874..b2abda227e 100644 --- a/src/providers/proxy/proxy_child.c +++ b/src/providers/proxy/proxy_child.c @@ -556,7 +556,10 @@ int main(int argc, const char *argv[]) conf_entry = talloc_asprintf(NULL, CONFDB_DOMAIN_PATH_TMPL, domain); if (!conf_entry) return 2; - ret = server_setup(srv_name, 0, 0, 0, conf_entry, &main_ctx); + sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_RID); + sss_chain_id_set(chain_id); + + ret = server_setup(srv_name, false, 0, 0, 0, conf_entry, &main_ctx); if (ret != EOK) { DEBUG(SSSDBG_FATAL_FAILURE, "Could not set up mainloop [%d]\n", ret); return 2; diff --git a/src/responder/autofs/autofssrv.c b/src/responder/autofs/autofssrv.c index 2f2271312b..a14ab2c8b9 100644 --- a/src/responder/autofs/autofssrv.c +++ b/src/responder/autofs/autofssrv.c @@ -213,7 +213,7 @@ int main(int argc, const char *argv[]) debug_log_file = "sssd_autofs"; DEBUG_INIT(debug_level, opt_logger); - ret = server_setup("autofs", 0, uid, gid, + ret = server_setup("autofs", true, 0, uid, gid, CONFDB_AUTOFS_CONF_ENTRY, &main_ctx); if (ret != EOK) { return 2; diff --git a/src/responder/common/responder_common.c b/src/responder/common/responder_common.c index 2b95faabe3..6652cc46db 100644 --- a/src/responder/common/responder_common.c +++ b/src/responder/common/responder_common.c @@ -1319,8 +1319,6 @@ int sss_process_init(TALLOC_CTX *mem_ctx, goto fail; } - sss_chain_id_setup(rctx->ev); - /* Ensure that the client timeout is at least ten seconds */ if (rctx->client_idle_timeout < 10) { rctx->client_idle_timeout = 10; diff --git a/src/responder/ifp/ifpsrv.c b/src/responder/ifp/ifpsrv.c index d27c2dfccd..d098f5652c 100644 --- a/src/responder/ifp/ifpsrv.c +++ b/src/responder/ifp/ifpsrv.c @@ -339,7 +339,7 @@ int main(int argc, const char *argv[]) debug_log_file = "sssd_ifp"; DEBUG_INIT(debug_level, opt_logger); - ret = server_setup("ifp", 0, 0, 0, + ret = server_setup("ifp", true, 0, 0, 0, CONFDB_IFP_CONF_ENTRY, &main_ctx); if (ret != EOK) return 2; diff --git a/src/responder/kcm/kcm.c b/src/responder/kcm/kcm.c index 36295560a2..7ff3d0253a 100644 --- a/src/responder/kcm/kcm.c +++ b/src/responder/kcm/kcm.c @@ -357,7 +357,7 @@ int main(int argc, const char *argv[]) debug_log_file = "sssd_kcm"; DEBUG_INIT(debug_level, opt_logger); - ret = server_setup("kcm", 0, uid, gid, CONFDB_KCM_CONF_ENTRY, + ret = server_setup("kcm", true, 0, uid, gid, CONFDB_KCM_CONF_ENTRY, &main_ctx); if (ret != EOK) return 2; diff --git a/src/responder/nss/nsssrv.c b/src/responder/nss/nsssrv.c index 526d97b087..32eb99f27c 100644 --- a/src/responder/nss/nsssrv.c +++ b/src/responder/nss/nsssrv.c @@ -664,7 +664,7 @@ int main(int argc, const char *argv[]) debug_log_file = "sssd_nss"; DEBUG_INIT(debug_level, opt_logger); - ret = server_setup("nss", 0, uid, gid, CONFDB_NSS_CONF_ENTRY, + ret = server_setup("nss", true, 0, uid, gid, CONFDB_NSS_CONF_ENTRY, &main_ctx); if (ret != EOK) return 2; diff --git a/src/responder/pac/pacsrv.c b/src/responder/pac/pacsrv.c index e77641ec01..5c373205e4 100644 --- a/src/responder/pac/pacsrv.c +++ b/src/responder/pac/pacsrv.c @@ -202,7 +202,7 @@ int main(int argc, const char *argv[]) debug_log_file = "sssd_pac"; DEBUG_INIT(debug_level, opt_logger); - ret = server_setup("pac", 0, uid, gid, + ret = server_setup("pac", true, 0, uid, gid, CONFDB_PAC_CONF_ENTRY, &main_ctx); if (ret != EOK) return 2; diff --git a/src/responder/pam/pamsrv.c b/src/responder/pam/pamsrv.c index 14aa094360..831120508b 100644 --- a/src/responder/pam/pamsrv.c +++ b/src/responder/pam/pamsrv.c @@ -489,7 +489,7 @@ int main(int argc, const char *argv[]) "debugging might not work!\n"); } - ret = server_setup("pam", 0, uid, gid, CONFDB_PAM_CONF_ENTRY, &main_ctx); + ret = server_setup("pam", true, 0, uid, gid, CONFDB_PAM_CONF_ENTRY, &main_ctx); if (ret != EOK) return 2; ret = die_if_parent_died(); diff --git a/src/responder/ssh/sshsrv.c b/src/responder/ssh/sshsrv.c index bd5a42e6da..95835a7db2 100644 --- a/src/responder/ssh/sshsrv.c +++ b/src/responder/ssh/sshsrv.c @@ -208,7 +208,7 @@ int main(int argc, const char *argv[]) "debugging might not work!\n"); } - ret = server_setup("ssh", 0, uid, gid, + ret = server_setup("ssh", true, 0, uid, gid, CONFDB_SSH_CONF_ENTRY, &main_ctx); if (ret != EOK) { return 2; diff --git a/src/responder/sudo/sudosrv.c b/src/responder/sudo/sudosrv.c index d7ab0cecf5..5fb9bfcac2 100644 --- a/src/responder/sudo/sudosrv.c +++ b/src/responder/sudo/sudosrv.c @@ -196,7 +196,7 @@ int main(int argc, const char *argv[]) } } - ret = server_setup("sudo", 0, uid, gid, CONFDB_SUDO_CONF_ENTRY, + ret = server_setup("sudo", true, 0, uid, gid, CONFDB_SUDO_CONF_ENTRY, &main_ctx); if (ret != EOK) { return 2; diff --git a/src/tests/cwrap/test_server.c b/src/tests/cwrap/test_server.c index 85ecb7f74d..c026c9f733 100644 --- a/src/tests/cwrap/test_server.c +++ b/src/tests/cwrap/test_server.c @@ -101,7 +101,7 @@ void test_run_as_root_fg(void **state) pid = fork(); if (pid == 0) { - ret = server_setup(__FUNCTION__, 0, 0, 0, + ret = server_setup(__FUNCTION__, false, 0, 0, 0, __FUNCTION__, &main_ctx); assert_int_equal(ret, 0); exit(0); @@ -124,7 +124,7 @@ void test_run_as_sssd_fg(void **state) pid = fork(); if (pid == 0) { - ret = server_setup(__FUNCTION__, 0, sssd->pw_uid, sssd->pw_gid, + ret = server_setup(__FUNCTION__, false, 0, sssd->pw_uid, sssd->pw_gid, __FUNCTION__, &main_ctx); assert_int_equal(ret, 0); exit(0); @@ -149,7 +149,7 @@ void test_run_as_root_daemon(void **state) pid = fork(); if (pid == 0) { - ret = server_setup(__FUNCTION__, FLAGS_PID_FILE, + ret = server_setup(__FUNCTION__, false, FLAGS_PID_FILE, 0, 0, __FUNCTION__, &main_ctx); assert_int_equal(ret, 0); diff --git a/src/util/server.c b/src/util/server.c index e3133a61dd..b10526786d 100644 --- a/src/util/server.c +++ b/src/util/server.c @@ -33,6 +33,7 @@ #include <ldb.h> #include "util/util.h" #include "confdb/confdb.h" +#include "util/sss_chain_id_tevent.h" #ifdef HAVE_PRCTL #include <sys/prctl.h> @@ -451,7 +452,8 @@ static const char *get_pid_path(void) #endif } -int server_setup(const char *name, int flags, +int server_setup(const char *name, bool is_responder, + int flags, uid_t uid, gid_t gid, const char *conf_entry, struct main_context **main_ctx) @@ -703,6 +705,12 @@ int server_setup(const char *name, int flags, } } + if (is_responder) { + sss_chain_id_setup(ctx->event_ctx, DEBUG_CHAIN_ID_FMT_CID); + } else { + sss_chain_id_setup(ctx->event_ctx, DEBUG_CHAIN_ID_FMT_RID); + } + sss_log(SSS_LOG_INFO, "Starting up"); DEBUG(SSSDBG_TRACE_FUNC, "CONFDB: %s\n", conf_db); diff --git a/src/util/util.h b/src/util/util.h index 0102f94570..3aaea14a59 100644 --- a/src/util/util.h +++ b/src/util/util.h @@ -196,7 +196,8 @@ errno_t server_common_rotate_logs(struct confdb_ctx *confdb, int die_if_parent_died(void); int check_pidfile(const char *file); int pidfile(const char *file); -int server_setup(const char *name, int flags, +int server_setup(const char *name, bool is_responder, + int flags, uid_t uid, gid_t gid, const char *conf_entry, struct main_context **main_ctx); From 50b4df325699b8176259fcbb9829a4d8c2fd1f5b Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 16:39:07 +0000 Subject: [PATCH 07/16] krb5_child: Add chain ID logging support --- Makefile.am | 1 + src/providers/krb5/krb5_auth.h | 1 + src/providers/krb5/krb5_child.c | 4 ++++ src/providers/krb5/krb5_child_handler.c | 13 +++++++++++++ src/tests/cmocka/test_krb5_common.c | 18 ++++++++++++------ 5 files changed, 31 insertions(+), 6 deletions(-) diff --git a/Makefile.am b/Makefile.am index 54a681bc53..4e72d6c1bf 100644 --- a/Makefile.am +++ b/Makefile.am @@ -4513,6 +4513,7 @@ krb5_child_SOURCES = \ src/util/util.c \ src/util/util_ext.c \ src/util/signal.c \ + src/util/sss_chain_id.c \ src/util/strtonum.c \ src/util/become_user.c \ src/util/util_errors.c \ diff --git a/src/providers/krb5/krb5_auth.h b/src/providers/krb5/krb5_auth.h index c706625f6f..575bc0f0bc 100644 --- a/src/providers/krb5/krb5_auth.h +++ b/src/providers/krb5/krb5_auth.h @@ -47,6 +47,7 @@ #define CHILD_OPT_FAST_PRINCIPAL "fast-principal" #define CHILD_OPT_CANONICALIZE "canonicalize" #define CHILD_OPT_SSS_CREDS_PASSWORD "sss-creds-password" +#define CHILD_OPT_CHAIN_ID "chain-id" struct krb5child_req { struct pam_data *pd; diff --git a/src/providers/krb5/krb5_child.c b/src/providers/krb5/krb5_child.c index fdc111fd46..3512456ced 100644 --- a/src/providers/krb5/krb5_child.c +++ b/src/providers/krb5/krb5_child.c @@ -36,6 +36,7 @@ #include "util/user_info_msg.h" #include "util/child_common.h" #include "util/find_uid.h" +#include "util/sss_chain_id.h" #include "src/util/util_errors.h" #include "providers/backend.h" #include "providers/krb5/krb5_auth.h" @@ -3317,6 +3318,7 @@ int main(int argc, const char *argv[]) krb5_error_code kerr; uid_t fast_uid = 0; gid_t fast_gid = 0; + uint64_t chain_id = 0; struct cli_opts cli_opts = { 0 }; int sss_creds_password = 0; @@ -3345,6 +3347,8 @@ int main(int argc, const char *argv[]) _("Requests canonicalization of the principal name"), NULL}, {CHILD_OPT_SSS_CREDS_PASSWORD, 0, POPT_ARG_NONE, &sss_creds_password, 0, _("Use custom version of krb5_get_init_creds_password"), NULL}, + {CHILD_OPT_CHAIN_ID, 0, POPT_ARG_LONG, &chain_id, + 0, _("Tevent chain ID used for logging purposes"), NULL}, POPT_TABLEEND }; diff --git a/src/providers/krb5/krb5_child_handler.c b/src/providers/krb5/krb5_child_handler.c index 778e38fc8e..ca156dd538 100644 --- a/src/providers/krb5/krb5_child_handler.c +++ b/src/providers/krb5/krb5_child_handler.c @@ -26,6 +26,7 @@ #include "util/util.h" #include "util/child_common.h" +#include "util/sss_chain_id.h" #include "providers/krb5/krb5_common.h" #include "providers/krb5/krb5_auth.h" #include "src/providers/krb5/krb5_utils.h" @@ -301,6 +302,7 @@ errno_t set_extra_args(TALLOC_CTX *mem_ctx, struct krb5_ctx *krb5_ctx, { const char **extra_args; const char *krb5_realm; + uint64_t chain_id; size_t c = 0; int ret; @@ -418,6 +420,17 @@ errno_t set_extra_args(TALLOC_CTX *mem_ctx, struct krb5_ctx *krb5_ctx, c++; } + chain_id = sss_chain_id_get(); + extra_args[c] = talloc_asprintf(extra_args, + "--"CHILD_OPT_CHAIN_ID"=%lu", + chain_id); + if (extra_args[c] == NULL) { + DEBUG(SSSDBG_OP_FAILURE, "talloc_asprintf failed.\n"); + ret = ENOMEM; + goto done; + } + c++; + extra_args[c] = NULL; *krb5_child_extra_args = extra_args; diff --git a/src/tests/cmocka/test_krb5_common.c b/src/tests/cmocka/test_krb5_common.c index c43d836ad5..4bf3237a73 100644 --- a/src/tests/cmocka/test_krb5_common.c +++ b/src/tests/cmocka/test_krb5_common.c @@ -103,7 +103,8 @@ void test_set_extra_args(void **state) assert_int_equal(ret, EOK); assert_string_equal(krb5_child_extra_args[0], uid_opt); assert_string_equal(krb5_child_extra_args[1], gid_opt); - assert_null(krb5_child_extra_args[2]); + assert_string_equal(krb5_child_extra_args[2], "--chain-id=0"); + assert_null(krb5_child_extra_args[3]); talloc_free(krb5_child_extra_args); krb5_ctx->canonicalize = true; @@ -113,7 +114,8 @@ void test_set_extra_args(void **state) assert_string_equal(krb5_child_extra_args[0], uid_opt); assert_string_equal(krb5_child_extra_args[1], gid_opt); assert_string_equal(krb5_child_extra_args[2], "--canonicalize"); - assert_null(krb5_child_extra_args[3]); + assert_string_equal(krb5_child_extra_args[3], "--chain-id=0"); + assert_null(krb5_child_extra_args[4]); talloc_free(krb5_child_extra_args); krb5_ctx->realm = discard_const(TEST_REALM); @@ -124,7 +126,8 @@ void test_set_extra_args(void **state) assert_string_equal(krb5_child_extra_args[1], gid_opt); assert_string_equal(krb5_child_extra_args[2], "--realm=" TEST_REALM); assert_string_equal(krb5_child_extra_args[3], "--canonicalize"); - assert_null(krb5_child_extra_args[4]); + assert_string_equal(krb5_child_extra_args[4], "--chain-id=0"); + assert_null(krb5_child_extra_args[5]); talloc_free(krb5_child_extra_args); /* --fast-principal will be only set if FAST is used */ @@ -136,7 +139,8 @@ void test_set_extra_args(void **state) assert_string_equal(krb5_child_extra_args[1], gid_opt); assert_string_equal(krb5_child_extra_args[2], "--realm=" TEST_REALM); assert_string_equal(krb5_child_extra_args[3], "--canonicalize"); - assert_null(krb5_child_extra_args[4]); + assert_string_equal(krb5_child_extra_args[4], "--chain-id=0"); + assert_null(krb5_child_extra_args[5]); talloc_free(krb5_child_extra_args); krb5_ctx->use_fast_str = discard_const(TEST_FAST_STR); @@ -150,7 +154,8 @@ void test_set_extra_args(void **state) assert_string_equal(krb5_child_extra_args[4], "--fast-principal=" TEST_FAST_PRINC); assert_string_equal(krb5_child_extra_args[5], "--canonicalize"); - assert_null(krb5_child_extra_args[6]); + assert_string_equal(krb5_child_extra_args[6], "--chain-id=0"); + assert_null(krb5_child_extra_args[7]); talloc_free(krb5_child_extra_args); krb5_ctx->lifetime_str = discard_const(TEST_LIFE_STR); @@ -168,7 +173,8 @@ void test_set_extra_args(void **state) assert_string_equal(krb5_child_extra_args[6], "--fast-principal=" TEST_FAST_PRINC); assert_string_equal(krb5_child_extra_args[7], "--canonicalize"); - assert_null(krb5_child_extra_args[8]); + assert_string_equal(krb5_child_extra_args[8], "--chain-id=0"); + assert_null(krb5_child_extra_args[9]); talloc_free(krb5_child_extra_args); talloc_free(krb5_ctx); From 40ebb93674183268fe7c0f9c5c70d43e208034ce Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 17:01:38 +0000 Subject: [PATCH 08/16] gpo: Add chain ID logging support --- Makefile.am | 3 ++- src/providers/ad/ad_gpo.c | 18 +++++++++++++++++- src/providers/ad/ad_gpo_child.c | 5 +++++ 3 files changed, 24 insertions(+), 2 deletions(-) diff --git a/Makefile.am b/Makefile.am index 4e72d6c1bf..33f2dcb14e 100644 --- a/Makefile.am +++ b/Makefile.am @@ -4589,7 +4589,8 @@ gpo_child_SOURCES = \ src/util/atomic_io.c \ src/util/util.c \ src/util/util_ext.c \ - src/util/signal.c + src/util/signal.c \ + src/util/sss_chain_id.c gpo_child_CFLAGS = \ $(AM_CFLAGS) \ $(POPT_CFLAGS) \ diff --git a/src/providers/ad/ad_gpo.c b/src/providers/ad/ad_gpo.c index 8f2fe277e1..fa8727d4d4 100644 --- a/src/providers/ad/ad_gpo.c +++ b/src/providers/ad/ad_gpo.c @@ -50,6 +50,7 @@ #include "providers/ldap/sdap.h" #include "providers/ldap/sdap_idmap.h" #include "util/util_sss_idmap.h" +#include "util/sss_chain_id.h" #include <ndr.h> #include <gen_ndr/security.h> #include <db/sysdb_computer.h> @@ -4793,10 +4794,25 @@ gpo_fork_child(struct tevent_req *req) int pipefd_from_child[2] = PIPE_INIT; pid_t pid; errno_t ret; + const char **extra_args; + int c = 0; struct ad_gpo_process_cse_state *state; state = tevent_req_data(req, struct ad_gpo_process_cse_state); + extra_args = talloc_array(state, const char *, 2); + + extra_args[c] = talloc_asprintf(extra_args, "--chain-id=%lu", + sss_chain_id_get()); + if (extra_args[c] == NULL) { + DEBUG(SSSDBG_OP_FAILURE, "talloc_asprintf failed.\n"); + ret = ENOMEM; + goto fail; + } + c++; + + extra_args[c] = NULL; + ret = pipe(pipefd_from_child); if (ret == -1) { ret = errno; @@ -4817,7 +4833,7 @@ gpo_fork_child(struct tevent_req *req) if (pid == 0) { /* child */ exec_child_ex(state, pipefd_to_child, pipefd_from_child, - GPO_CHILD, GPO_CHILD_LOG_FILE, NULL, false, + GPO_CHILD, GPO_CHILD_LOG_FILE, extra_args, false, STDIN_FILENO, AD_GPO_CHILD_OUT_FILENO); /* We should never get here */ diff --git a/src/providers/ad/ad_gpo_child.c b/src/providers/ad/ad_gpo_child.c index 2e5c5c3f69..f9e9cb092e 100644 --- a/src/providers/ad/ad_gpo_child.c +++ b/src/providers/ad/ad_gpo_child.c @@ -33,6 +33,7 @@ #include "util/util.h" #include "util/child_common.h" +#include "util/sss_chain_id.h" #include "providers/backend.h" #include "providers/ad/ad_gpo.h" #include "sss_cli.h" @@ -724,6 +725,7 @@ main(int argc, const char *argv[]) int opt; poptContext pc; int debug_fd = -1; + uint64_t chain_id; const char *opt_logger = NULL; errno_t ret; int sysvol_gpt_version; @@ -740,6 +742,8 @@ main(int argc, const char *argv[]) SSSD_DEBUG_OPTS {"debug-fd", 0, POPT_ARG_INT, &debug_fd, 0, _("An open file descriptor for the debug logs"), NULL}, + {"chain-id", 0, POPT_ARG_LONG, &chain_id, + 0, _("Tevent chain ID used for logging purposes"), NULL}, SSSD_LOGGER_OPTS POPT_TABLEEND }; @@ -776,6 +780,7 @@ main(int argc, const char *argv[]) } sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_RID); + sss_chain_id_set(chain_id); DEBUG_INIT(debug_level, opt_logger); From 02542596660ddc5c22d842e48b76124e3a1b0d65 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 18:20:29 +0000 Subject: [PATCH 09/16] ipa_selinux: Add chain ID logging support --- Makefile.am | 1 + src/providers/ipa/ipa_selinux.c | 21 +++++++++++++++++++-- src/providers/ipa/selinux_child.c | 4 ++++ 3 files changed, 24 insertions(+), 2 deletions(-) diff --git a/Makefile.am b/Makefile.am index 33f2dcb14e..93978c154d 100644 --- a/Makefile.am +++ b/Makefile.am @@ -4565,6 +4565,7 @@ if BUILD_SEMANAGE selinux_child_SOURCES = \ src/providers/ipa/selinux_child.c \ src/util/sss_semanage.c \ + src/util/sss_chain_id.c \ src/util/atomic_io.c \ src/util/util.c \ src/util/util_ext.c \ diff --git a/src/providers/ipa/ipa_selinux.c b/src/providers/ipa/ipa_selinux.c index 7603491342..6f885c0fdb 100644 --- a/src/providers/ipa/ipa_selinux.c +++ b/src/providers/ipa/ipa_selinux.c @@ -26,6 +26,7 @@ #include "db/sysdb_selinux.h" #include "util/child_common.h" #include "util/sss_selinux.h" +#include "util/sss_chain_id.h" #include "providers/ldap/sdap_async.h" #include "providers/ipa/ipa_common.h" #include "providers/ipa/ipa_config.h" @@ -676,6 +677,21 @@ static errno_t selinux_fork_child(struct selinux_child_state *state) int pipefd_from_child[2]; pid_t pid; errno_t ret; + const char **extra_args; + int c = 0; + + extra_args = talloc_array(state, const char *, 2); + + extra_args[c] = talloc_asprintf(extra_args, "--chain-id=%lu", + sss_chain_id_get()); + if (extra_args[c] == NULL) { + DEBUG(SSSDBG_OP_FAILURE, "talloc_asprintf failed.\n"); + ret = ENOMEM; + return ret; + } + c++; + + extra_args[c] = NULL; ret = pipe(pipefd_from_child); if (ret == -1) { @@ -696,8 +712,9 @@ static errno_t selinux_fork_child(struct selinux_child_state *state) pid = fork(); if (pid == 0) { /* child */ - exec_child(state, pipefd_to_child, pipefd_from_child, - SELINUX_CHILD, SELINUX_CHILD_LOG_FILE); + exec_child_ex(state, pipefd_to_child, pipefd_from_child, + SELINUX_CHILD, SELINUX_CHILD_LOG_FILE, extra_args, + false, STDIN_FILENO, STDERR_FILENO); DEBUG(SSSDBG_CRIT_FAILURE, "Could not exec selinux_child: [%d][%s].\n", ret, sss_strerror(ret)); return ret; diff --git a/src/providers/ipa/selinux_child.c b/src/providers/ipa/selinux_child.c index db8ece5719..d4f8d99009 100644 --- a/src/providers/ipa/selinux_child.c +++ b/src/providers/ipa/selinux_child.c @@ -30,6 +30,7 @@ #include "util/util.h" #include "util/child_common.h" +#include "util/sss_chain_id.h" #include "providers/backend.h" struct input_buffer { @@ -217,12 +218,15 @@ int main(int argc, const char *argv[]) bool needs_update; const char *username; const char *opt_logger = NULL; + uint64_t chain_id; struct poptOption long_options[] = { POPT_AUTOHELP SSSD_DEBUG_OPTS {"debug-fd", 0, POPT_ARG_INT, &debug_fd, 0, _("An open file descriptor for the debug logs"), NULL}, + {"chain-id", 0, POPT_ARG_LONG, &chain_id, + 0, _("Tevent chain ID used for logging purposes"), NULL}, SSSD_LOGGER_OPTS POPT_TABLEEND }; From 8eeac5c1b22ee69873a43817e9382a054a01f33f Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 18:32:13 +0000 Subject: [PATCH 10/16] p11_child: Add chain ID logging support --- Makefile.am | 1 + src/p11_child/p11_child_common.c | 5 +++++ src/responder/pam/pamsrv_p11.c | 10 +++++++++- 3 files changed, 15 insertions(+), 1 deletion(-) diff --git a/Makefile.am b/Makefile.am index 93978c154d..f1f83384bc 100644 --- a/Makefile.am +++ b/Makefile.am @@ -4627,6 +4627,7 @@ p11_child_SOURCES = \ src/util/atomic_io.c \ src/util/util.c \ src/util/util_ext.c \ + src/util/sss_chain_id.c \ $(NULL) p11_child_SOURCES += src/p11_child/p11_child_openssl.c diff --git a/src/p11_child/p11_child_common.c b/src/p11_child/p11_child_common.c index f691ab6363..9d884a43f5 100644 --- a/src/p11_child/p11_child_common.c +++ b/src/p11_child/p11_child_common.c @@ -33,6 +33,7 @@ #include "providers/backend.h" #include "util/crypto/sss_crypto.h" #include "util/cert.h" +#include "util/sss_chain_id.h" #include "p11_child/p11_child.h" static const char *op_mode_str(enum op_mode mode) @@ -161,6 +162,7 @@ int main(int argc, const char *argv[]) char *key_id = NULL; char *label = NULL; char *cert_b64 = NULL; + uint64_t chain_id = 0; bool wait_for_card = false; char *uri = NULL; @@ -194,6 +196,8 @@ int main(int argc, const char *argv[]) _("certificate to verify, base64 encoded"), NULL}, {"uri", 0, POPT_ARG_STRING, &uri, 0, _("PKCS#11 URI to restrict selection"), NULL}, + {"chain-id", 0, POPT_ARG_LONG, &chain_id, + 0, _("Tevent chain ID used for logging purposes"), NULL}, POPT_TABLEEND }; @@ -314,6 +318,7 @@ int main(int argc, const char *argv[]) } sss_chain_id_set_format(DEBUG_CHAIN_ID_FMT_CID); + sss_chain_id_set(chain_id); DEBUG_INIT(debug_level, opt_logger); diff --git a/src/responder/pam/pamsrv_p11.c b/src/responder/pam/pamsrv_p11.c index 3b21332db9..0ad7d7590e 100644 --- a/src/responder/pam/pamsrv_p11.c +++ b/src/responder/pam/pamsrv_p11.c @@ -29,6 +29,7 @@ #include "responder/pam/pam_helpers.h" #include "lib/certmap/sss_certmap.h" #include "util/crypto/sss_crypto.h" +#include "util/sss_chain_id.h" #include "db/sysdb.h" @@ -718,10 +719,11 @@ struct tevent_req *pam_check_cert_send(TALLOC_CTX *mem_ctx, struct timeval tv; int pipefd_to_child[2] = PIPE_INIT; int pipefd_from_child[2] = PIPE_INIT; - const char *extra_args[16] = { NULL }; + const char *extra_args[18] = { NULL }; uint8_t *write_buf = NULL; size_t write_buf_len = 0; size_t arg_c; + uint64_t chain_id; const char *module_name = NULL; const char *token_name = NULL; const char *key_id = NULL; @@ -746,6 +748,12 @@ struct tevent_req *pam_check_cert_send(TALLOC_CTX *mem_ctx, /* extra_args are added in revers order */ arg_c = 0; + + chain_id = sss_chain_id_get(); + + extra_args[arg_c++] = talloc_asprintf(mem_ctx, "%lu", chain_id); + extra_args[arg_c++] = "--chain-id"; + if (uri != NULL) { DEBUG(SSSDBG_TRACE_ALL, "Adding PKCS#11 URI [%s].\n", uri); extra_args[arg_c++] = uri; From 5b0b02da6e9cb95ff2e04b18e5fa1f94d3f74f5d Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Thu, 28 Oct 2021 17:41:47 +0000 Subject: [PATCH 11/16] proxy_child: Add chain ID logging support --- src/providers/proxy/proxy_auth.c | 6 ++++-- src/providers/proxy/proxy_child.c | 4 ++++ 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/src/providers/proxy/proxy_auth.c b/src/providers/proxy/proxy_auth.c index 0e6fc8ea84..9af1b1f669 100644 --- a/src/providers/proxy/proxy_auth.c +++ b/src/providers/proxy/proxy_auth.c @@ -26,6 +26,7 @@ #include "providers/proxy/proxy.h" #include "sss_iface/sss_iface_async.h" +#include "util/sss_chain_id.h" struct pc_init_ctx; @@ -178,11 +179,12 @@ static struct tevent_req *proxy_child_init_send(TALLOC_CTX *mem_ctx, state->command = talloc_asprintf(req, "%s/proxy_child -d %#.4x --debug-timestamps=%d " - "--debug-microseconds=%d --logger=%s --domain %s --id %d", + "--debug-microseconds=%d --logger=%s --domain %s --id %d " + "--chain-id=%lu", SSSD_LIBEXEC_PATH, debug_level, debug_timestamps, debug_microseconds, sss_logger_str[sss_logger], auth_ctx->be->domain->name, - child_ctx->id); + child_ctx->id, sss_chain_id_get()); if (state->command == NULL) { DEBUG(SSSDBG_CRIT_FAILURE, "talloc_asprintf failed.\n"); return NULL; diff --git a/src/providers/proxy/proxy_child.c b/src/providers/proxy/proxy_child.c index b2abda227e..624a01967e 100644 --- a/src/providers/proxy/proxy_child.c +++ b/src/providers/proxy/proxy_child.c @@ -43,6 +43,7 @@ #include "confdb/confdb.h" #include "providers/proxy/proxy.h" #include "sss_iface/sss_iface_async.h" +#include "util/sss_chain_id.h" #include "providers/backend.h" @@ -480,6 +481,7 @@ int main(int argc, const char *argv[]) struct main_context *main_ctx; int ret; long id = 0; + long chain_id; char *pam_target = NULL; uid_t uid; gid_t gid; @@ -493,6 +495,8 @@ int main(int argc, const char *argv[]) _("Domain of the information provider (mandatory)"), NULL }, {"id", 0, POPT_ARG_LONG, &id, 0, _("Child identifier (mandatory)"), NULL }, + {"chain-id", 0, POPT_ARG_LONG, &chain_id, 0, + _("Tevent chain ID used for logging purposes"), NULL }, POPT_TABLEEND }; From 92beb6afc83b9418986fa549533c6db6dd33e355 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Fri, 29 Oct 2021 14:37:49 +0000 Subject: [PATCH 12/16] Analyzer: Parse the responder request ID This is needed to parse out the responder request ID field properly. Due to Responder tevent chain ID support, the Request ID is in a different part of the log message. --- src/tools/analyzer/modules/request.py | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/src/tools/analyzer/modules/request.py b/src/tools/analyzer/modules/request.py index 0d7c906f31..c4137da53d 100644 --- a/src/tools/analyzer/modules/request.py +++ b/src/tools/analyzer/modules/request.py @@ -171,8 +171,8 @@ def print_formatted(self, line, verbose): if line.startswith(' * '): return fields = line.split("[") - cr_field = fields[2].split(":")[1] - cr = cr_field[5:] + cr_field = fields[3][7:] + cr = cr_field.split(":")[0][4:] if "refreshed" in line: return # CR Plugin name @@ -189,7 +189,7 @@ def print_formatted(self, line, verbose): ts = line.split(")")[0] ts = ts[1:] fields = line.split("[") - cid = fields[3][5:-1] + cid = fields[3][4:-9] cmd = fields[4][4:-1] uid = fields[5][4:-1] if not uid.isnumeric(): @@ -218,10 +218,11 @@ def list_requests(self, args): source = self.load(args) component = source.Component.NSS resp = "nss" + # Log messages matching the following regex patterns contain + # the useful info we need to produce list output patterns = ['\[cmd'] patterns.append("(cache_req_send|cache_req_process_input|" "cache_req_search_send)") - consume = True if args.pam: component = source.Component.PAM resp = "pam" @@ -229,7 +230,6 @@ def list_requests(self, args): logger.info(f"******** Listing {resp} client requests ********") source.set_component(component) self.done = "" - # For each CID for line in self.matched_line(source, patterns): if isinstance(source, Journald): print(line) @@ -255,7 +255,8 @@ def track_request(self, args): if args.pam: component = source.Component.PAM resp = "pam" - pam_data_regex = f'pam_print_data.*\[CID #{cid}\]' + pam_data_regex = f'pam.*\[CID#{cid}\]' + pattern.append(pam_data_regex) logger.info(f"******** Checking {resp} responder for Client ID" f" {cid} *******") From 7a365e88627211c493c660e6d0c2b02b1cd9d266 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Thu, 4 Nov 2021 00:05:20 +0000 Subject: [PATCH 13/16] Analyzer: Add --child argument to 'request show' The analyzer tool will search for requests (RID# log messages) in any existing child log files when --child is provided. --- src/tools/analyzer/modules/request.py | 15 ++++----------- src/tools/analyzer/source_files.py | 14 +++++++++----- src/tools/analyzer/source_journald.py | 2 +- 3 files changed, 14 insertions(+), 17 deletions(-) diff --git a/src/tools/analyzer/modules/request.py b/src/tools/analyzer/modules/request.py index c4137da53d..6fd46f99d1 100644 --- a/src/tools/analyzer/modules/request.py +++ b/src/tools/analyzer/modules/request.py @@ -28,7 +28,7 @@ class RequestAnalyzer: show_opts = [ Option('cid', 'Track request with this ID', int), - Option('--cachereq', 'Include cache request logs', bool), + Option('--child', 'Include child process logs', bool), Option('--merge', 'Merge logs together sorted by timestamp', bool), Option('--pam', 'Track only PAM requests', bool), ] @@ -228,7 +228,7 @@ def list_requests(self, args): resp = "pam" logger.info(f"******** Listing {resp} client requests ********") - source.set_component(component) + source.set_component(component, False) self.done = "" for line in self.matched_line(source, patterns): if isinstance(source, Journald): @@ -260,18 +260,13 @@ def track_request(self, args): logger.info(f"******** Checking {resp} responder for Client ID" f" {cid} *******") - source.set_component(component) - if args.cachereq: - cr_id_regex = 'CR #[0-9]+' - cr_ids = self.get_linked_ids(source, pattern, cr_id_regex) - [pattern.append(f'{id}\:') for id in cr_ids] - + source.set_component(component, args.child) for match in self.matched_line(source, pattern): resp_results = self.consume_line(match, source, args.merge) logger.info(f"********* Checking Backend for Client ID {cid} ********") pattern = [f'REQ_TRACE.*\[sssd.{resp} CID #{cid}\]'] - source.set_component(source.Component.BE) + source.set_component(source.Component.BE, args.child) be_id_regex = '\[RID#[0-9]+\]' be_ids = self.get_linked_ids(source, pattern, be_id_regex) @@ -279,8 +274,6 @@ def track_request(self, args): pattern.clear() [pattern.append(f'\\{id}') for id in be_ids] - if args.pam: - pattern.append(pam_data_regex) for match in self.matched_line(source, pattern): be_results = self.consume_line(match, source, args.merge) diff --git a/src/tools/analyzer/source_files.py b/src/tools/analyzer/source_files.py index df87f92fbd..90496a72eb 100644 --- a/src/tools/analyzer/source_files.py +++ b/src/tools/analyzer/source_files.py @@ -46,19 +46,22 @@ def resolve_path(self, path): else: return path + "/" - def get_domain_logfiles(self): + def get_domain_logfiles(self, child=False): """ Retrieve list of SSSD log files, exclude rotated (.gz) files """ domain_files = [] exclude_list = ["ifp", "nss", "pam", "sudo", "autofs", "ssh", "pac", "kcm", ".gz"] - file_list = glob.glob(self.path + "sssd_*") + if child: + file_list = glob.glob(self.path + "*.log") + else: + file_list = glob.glob(self.path + "sssd_*") for file in file_list: if not any(s in file for s in exclude_list): domain_files.append(file) return domain_files - def set_component(self, component): + def set_component(self, component, child): """ Switch the reader to interact with a certain SSSD component NSS, PAM, BE @@ -69,8 +72,9 @@ def set_component(self, component): elif component == self.Component.PAM: self.log_files.append(self.path + "sssd_pam.log") elif component == self.Component.BE: - if not self.domains: + domains = self.get_domain_logfiles(child) + if not domains: raise IOError # error: No domains found? - for dom in self.domains: + for dom in domains: self.log_files.append(dom) diff --git a/src/tools/analyzer/source_journald.py b/src/tools/analyzer/source_journald.py index 86d81d4854..71c8b894f4 100644 --- a/src/tools/analyzer/source_journald.py +++ b/src/tools/analyzer/source_journald.py @@ -33,7 +33,7 @@ def __iter__(self): else: yield msg - def set_component(self, component): + def set_component(self, component, child): """ Switch the reader to interact with a certain SSSD component NSS, PAM, BE From e844819b3d08a5ffa880425cf20f59b54cd8e57f Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Wed, 10 Nov 2021 21:08:38 +0000 Subject: [PATCH 14/16] Analyzer: Search all responder log files With the tevent chain ID logged into all responder debug messages, the analyzer can search responders for [CID#X] in 'request show' output. --- src/tools/analyzer/modules/request.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/tools/analyzer/modules/request.py b/src/tools/analyzer/modules/request.py index 6fd46f99d1..7f95f71697 100644 --- a/src/tools/analyzer/modules/request.py +++ b/src/tools/analyzer/modules/request.py @@ -250,13 +250,11 @@ def track_request(self, args): component = source.Component.NSS resp = "nss" pattern = [f'REQ_TRACE.*\[CID #{cid}\\]'] - pattern.append(f"\[CID #{cid}\\].*connected") + pattern.append(f"\[CID#{cid}\\]") if args.pam: component = source.Component.PAM resp = "pam" - pam_data_regex = f'pam.*\[CID#{cid}\]' - pattern.append(pam_data_regex) logger.info(f"******** Checking {resp} responder for Client ID" f" {cid} *******") From 42730d8268764f1c346cb4e9ad4f0a6ef935b792 Mon Sep 17 00:00:00 2001 From: Stanislav Levin <s...@altlinux.org> Date: Wed, 27 Oct 2021 10:18:50 +0300 Subject: [PATCH 15/16] sss-analyze: Fix self imports - fixed self imports to allow any other Python stuff use `sssd` Python package - tranformed `sssd` Python package from namespace to regular one - moved the executable out to libexec directory to split library and actual executable (sss_analyze is not intended to be a standalone tool) - fixed W0611(unused-import) found by Pylint Resolves: https://github.com/SSSD/sssd/issues/5842 Signed-off-by: Stanislav Levin <s...@altlinux.org> --- Makefile.am | 1 - contrib/sssd.spec.in | 3 ++- src/tools/analyzer/Makefile.am | 11 ++++++++--- src/tools/analyzer/__init__.py | 0 src/tools/analyzer/modules/request.py | 8 ++------ src/tools/analyzer/source_files.py | 6 +----- src/tools/analyzer/source_journald.py | 3 +-- src/tools/analyzer/sss_analyze | 5 +++++ src/tools/analyzer/sss_analyze.py | 11 ++++------- src/tools/sssctl/sssctl_logs.c | 2 +- 10 files changed, 24 insertions(+), 26 deletions(-) create mode 100644 src/tools/analyzer/__init__.py create mode 100755 src/tools/analyzer/sss_analyze mode change 100755 => 100644 src/tools/analyzer/sss_analyze.py diff --git a/Makefile.am b/Makefile.am index f1f83384bc..a82c3326d6 100644 --- a/Makefile.am +++ b/Makefile.am @@ -1921,7 +1921,6 @@ sssctl_LDADD = \ $(NULL) sssctl_CFLAGS = \ $(AM_CFLAGS) \ - -DPYTHONDIR_PATH=\"$(python3dir)/sssd\" \ $(NULL) if BUILD_SUDO diff --git a/contrib/sssd.spec.in b/contrib/sssd.spec.in index 130bcade0f..e3eb12b402 100644 --- a/contrib/sssd.spec.in +++ b/contrib/sssd.spec.in @@ -537,7 +537,7 @@ autoreconf -ivf %make_build all docs runstatedir=%{_rundir} -%py3_shebang_fix src/tools/analyzer/sss_analyze.py +%py3_shebang_fix src/tools/analyzer/sss_analyze sed -i -e 's:/usr/bin/python:/usr/bin/python3:' src/tools/sss_obfuscate %check @@ -877,6 +877,7 @@ done %{_sbindir}/sss_debuglevel %{_sbindir}/sss_seed %{_sbindir}/sssctl +%{_libexecdir}/%{servicename}/sss_analyze %{python3_sitelib}/sssd/ %{_mandir}/man8/sss_obfuscate.8* %{_mandir}/man8/sss_override.8* diff --git a/src/tools/analyzer/Makefile.am b/src/tools/analyzer/Makefile.am index d9f82aa61a..460e9e5b64 100644 --- a/src/tools/analyzer/Makefile.am +++ b/src/tools/analyzer/Makefile.am @@ -1,16 +1,21 @@ -pkgpythondir = $(python3dir)/sssd +sss_analyze_pythondir = $(libexecdir)/sssd -dist_pkgpython_SCRIPTS = \ - sss_analyze.py \ +dist_sss_analyze_python_SCRIPTS = \ + sss_analyze \ $(NULL) +pkgpythondir = $(python3dir)/sssd + dist_pkgpython_DATA = \ + __init__.py \ source_files.py \ source_journald.py \ source_reader.py \ + sss_analyze.py \ $(NULL) modulesdir = $(pkgpythondir)/modules dist_modules_DATA = \ + modules/__init__.py \ modules/request.py \ $(NULL) diff --git a/src/tools/analyzer/__init__.py b/src/tools/analyzer/__init__.py new file mode 100644 index 0000000000..e69de29bb2 diff --git a/src/tools/analyzer/modules/request.py b/src/tools/analyzer/modules/request.py index 7f95f71697..af37f68608 100644 --- a/src/tools/analyzer/modules/request.py +++ b/src/tools/analyzer/modules/request.py @@ -1,11 +1,8 @@ import re -import copy import logging -import argparse -from enum import Enum -from source_files import Files -from source_journald import Journald +from sssd.source_files import Files +from sssd.source_journald import Journald from sssd.sss_analyze import SubparsersAction from sssd.sss_analyze import Option from sssd.sss_analyze import Analyzer @@ -82,7 +79,6 @@ def load(self, args): Instantiated source object """ if args.source == "journald": - import source_journald source = Journald() else: source = Files(args.logdir) diff --git a/src/tools/analyzer/source_files.py b/src/tools/analyzer/source_files.py index 90496a72eb..0cadf99f03 100644 --- a/src/tools/analyzer/source_files.py +++ b/src/tools/analyzer/source_files.py @@ -1,11 +1,7 @@ -from enum import Enum -import configparser -from os import listdir -from os.path import isfile, join import glob import logging -from source_reader import Reader +from sssd.source_reader import Reader logger = logging.getLogger() diff --git a/src/tools/analyzer/source_journald.py b/src/tools/analyzer/source_journald.py index 71c8b894f4..22ec2ed09a 100644 --- a/src/tools/analyzer/source_journald.py +++ b/src/tools/analyzer/source_journald.py @@ -1,7 +1,6 @@ from systemd import journal -from source_reader import Reader -from enum import Enum +from sssd.source_reader import Reader _EXE_PREFIX = "/usr/libexec/sssd/" _NSS_MATCH = _EXE_PREFIX + "sssd_nss" diff --git a/src/tools/analyzer/sss_analyze b/src/tools/analyzer/sss_analyze new file mode 100755 index 0000000000..3f1beaf38b --- /dev/null +++ b/src/tools/analyzer/sss_analyze @@ -0,0 +1,5 @@ +#!/usr/bin/env python + +from sssd import sss_analyze + +sss_analyze.run() diff --git a/src/tools/analyzer/sss_analyze.py b/src/tools/analyzer/sss_analyze.py old mode 100755 new mode 100644 index b0603c32dc..6912372b15 --- a/src/tools/analyzer/sss_analyze.py +++ b/src/tools/analyzer/sss_analyze.py @@ -1,11 +1,5 @@ -#!/usr/bin/env python - import argparse -import source_files - -from modules import request - # Based on patch from https://bugs.python.org/issue9341 class SubparsersAction(argparse._SubParsersAction): @@ -116,6 +110,9 @@ def load_modules(self, parser, parser_grp): additional parsers attached. """ # Currently only the 'request' module exists + + # delayed import: the modules should be reorganized + from sssd.modules import request req = request.RequestAnalyzer() module_parser = req.setup_args(parser_grp) @@ -160,6 +157,6 @@ def main(self): args.func(args) -if __name__ == '__main__': +def run(): analyzer = Analyzer() analyzer.main() diff --git a/src/tools/sssctl/sssctl_logs.c b/src/tools/sssctl/sssctl_logs.c index b98cd68fec..717b4f3af2 100644 --- a/src/tools/sssctl/sssctl_logs.c +++ b/src/tools/sssctl/sssctl_logs.c @@ -41,7 +41,7 @@ #define LOG_FILE(file) " " LOG_PATH "/" file #define LOG_FILES LOG_FILE("*.log") -#define SSS_ANALYZE PYTHONDIR_PATH"/sss_analyze.py" +#define SSS_ANALYZE SSSD_LIBEXEC_PATH"/sss_analyze" #define CHECK(expr, done, msg) do { \ if (expr) { \ From bf38817478bf234adab6043b9ce60e45a76908b6 Mon Sep 17 00:00:00 2001 From: Justin Stephenson <jstep...@redhat.com> Date: Thu, 16 Dec 2021 13:10:45 -0500 Subject: [PATCH 16/16] Analyzer: Avoid circular import Addresses the following error: Traceback (most recent call last): File "/usr/libexec/sssd/sss_analyze", line 3, in <module> from sssd import sss_analyze File "/usr/lib/python3/site-packages/sssd/sss_analyze.py", line 3, in <module> from sssd.modules import request File "/usr/lib/python3/site-packages/sssd/modules/request.py", line 6, in <module> from sssd.sss_analyze import SubparsersAction ImportError: cannot import name 'SubparsersAction' from partially initialized module 'sssd.sss_analyze' (most likely due to a circular import) (/usr/lib/python3/site-packages/sssd/sss_analyze.py) --- src/tools/analyzer/Makefile.am | 1 + src/tools/analyzer/modules/request.py | 8 ++-- src/tools/analyzer/parser.py | 59 +++++++++++++++++++++++ src/tools/analyzer/sss_analyze.py | 67 ++------------------------- 4 files changed, 67 insertions(+), 68 deletions(-) create mode 100644 src/tools/analyzer/parser.py diff --git a/src/tools/analyzer/Makefile.am b/src/tools/analyzer/Makefile.am index 460e9e5b64..b40043d043 100644 --- a/src/tools/analyzer/Makefile.am +++ b/src/tools/analyzer/Makefile.am @@ -11,6 +11,7 @@ dist_pkgpython_DATA = \ source_files.py \ source_journald.py \ source_reader.py \ + parser.py \ sss_analyze.py \ $(NULL) diff --git a/src/tools/analyzer/modules/request.py b/src/tools/analyzer/modules/request.py index af37f68608..37055f6650 100644 --- a/src/tools/analyzer/modules/request.py +++ b/src/tools/analyzer/modules/request.py @@ -3,9 +3,8 @@ from sssd.source_files import Files from sssd.source_journald import Journald -from sssd.sss_analyze import SubparsersAction -from sssd.sss_analyze import Option -from sssd.sss_analyze import Analyzer +from sssd.parser import SubparsersAction +from sssd.parser import Option logger = logging.getLogger() @@ -39,7 +38,7 @@ def print_module_help(self, args): """ self.module_parser.print_help() - def setup_args(self, parser_grp): + def setup_args(self, parser_grp, cli): """ Setup module parser, subcommands, and options @@ -57,7 +56,6 @@ def setup_args(self, parser_grp): action=SubparsersAction, metavar='COMMANDS') - cli = Analyzer() subcmd_grp = subparser.add_parser_group('Operation Modes') cli.add_subcommand(subcmd_grp, 'list', 'List recent requests', self.list_requests, self.list_opts) diff --git a/src/tools/analyzer/parser.py b/src/tools/analyzer/parser.py new file mode 100644 index 0000000000..a7df0d0bc9 --- /dev/null +++ b/src/tools/analyzer/parser.py @@ -0,0 +1,59 @@ +import argparse + +# Based on patch from https://bugs.python.org/issue9341 +class SubparsersAction(argparse._SubParsersAction): + """ + Provide a subparser action that can create subparsers with ability of + grouping arguments. + + It is based on the patch from: + + - https://bugs.python.org/issue9341 + """ + + class _PseudoGroup(argparse.Action): + def __init__(self, container, title): + super().__init__(option_strings=[], dest=title) + self.container = container + self._choices_actions = [] + + def add_parser(self, name, **kwargs): + # add the parser to the main Action, but move the pseudo action + # in the group's own list + parser = self.container.add_parser(name, **kwargs) + choice_action = self.container._choices_actions.pop() + self._choices_actions.append(choice_action) + return parser + + def _get_subactions(self): + return self._choices_actions + + def add_parser_group(self, title): + # the formatter can handle recursive subgroups + grp = SubparsersAction._PseudoGroup(self, title) + self._choices_actions.append(grp) + return grp + + def add_parser_group(self, title): + """ + Add new parser group. + + :param title: Title. + :type title: str + :return: Parser group that can have additional parsers attached. + :rtype: ``argparse.Action`` extended with ``add_parser`` method + """ + grp = self._PseudoGroup(self, title) + self._choices_actions.append(grp) + return grp + + +class Option: + """ + Group option attributes for command/subcommand options + """ + def __init__(self, name, help_msg, opt_type, short_opt=None): + self.name = name + self.short_opt = short_opt + self.help_msg = help_msg + self.opt_type = opt_type diff --git a/src/tools/analyzer/sss_analyze.py b/src/tools/analyzer/sss_analyze.py index 6912372b15..be0c18e4f8 100644 --- a/src/tools/analyzer/sss_analyze.py +++ b/src/tools/analyzer/sss_analyze.py @@ -1,64 +1,7 @@ import argparse - -# Based on patch from https://bugs.python.org/issue9341 -class SubparsersAction(argparse._SubParsersAction): - """ - Provide a subparser action that can create subparsers with ability of - grouping arguments. - - It is based on the patch from: - - - https://bugs.python.org/issue9341 - """ - - class _PseudoGroup(argparse.Action): - def __init__(self, container, title): - super().__init__(option_strings=[], dest=title) - self.container = container - self._choices_actions = [] - - def add_parser(self, name, **kwargs): - # add the parser to the main Action, but move the pseudo action - # in the group's own list - parser = self.container.add_parser(name, **kwargs) - choice_action = self.container._choices_actions.pop() - self._choices_actions.append(choice_action) - return parser - - def _get_subactions(self): - return self._choices_actions - - def add_parser_group(self, title): - # the formatter can handle recursive subgroups - grp = SubparsersAction._PseudoGroup(self, title) - self._choices_actions.append(grp) - return grp - - def add_parser_group(self, title): - """ - Add new parser group. - - :param title: Title. - :type title: str - :return: Parser group that can have additional parsers attached. - :rtype: ``argparse.Action`` extended with ``add_parser`` method - """ - grp = self._PseudoGroup(self, title) - self._choices_actions.append(grp) - return grp - - -class Option: - """ - Group option attributes for command/subcommand options - """ - def __init__(self, name, help_msg, opt_type, short_opt=None): - self.name = name - self.short_opt = short_opt - self.help_msg = help_msg - self.opt_type = opt_type - +from sssd.modules import request +from sssd.parser import SubparsersAction class Analyzer: def add_subcommand(self, subcmd_grp, name, help_msg, func, opts): @@ -110,12 +53,10 @@ def load_modules(self, parser, parser_grp): additional parsers attached. """ # Currently only the 'request' module exists - - # delayed import: the modules should be reorganized - from sssd.modules import request req = request.RequestAnalyzer() + cli = Analyzer() - module_parser = req.setup_args(parser_grp) + module_parser = req.setup_args(parser_grp, cli) def setup_args(self): """
_______________________________________________ sssd-devel mailing list -- sssd-devel@lists.fedorahosted.org To unsubscribe send an email to sssd-devel-le...@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-devel@lists.fedorahosted.org Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure