The branch, master has been updated via 4580fd10468 winbind: send "debug traceid" from winbindd parent to child via 8da5ec60a8e winbind: enable "debug traceid" in main winbindd via 7c2d7930a36 docs-xml: document "winbind debug traceid" in smb.conf via f2fa3706ad9 s3:winbindd add "'winbind debug traceid" support via tevent tracing via e48fc192d24 debug: add debug_traceid_set/get() interface via 7dbb527751a debug: fix trailing whitespace via 463f694d5c6 s3:lib: reset all tevent trace callbacks in reinit_after_fork() via fa0430b21e4 s3:lib: fix trailing whitespaces from 29365195176 python: Use 'is' for identity when comparing against None
https://git.samba.org/?p=samba.git;a=shortlog;h=master - Log ----------------------------------------------------------------- commit 4580fd10468e22ea39cc38921fb0d8ad6be46339 Author: Pavel Filipenský <pfili...@redhat.com> Date: Sun Sep 5 20:37:55 2021 +0200 winbind: send "debug traceid" from winbindd parent to child Bumping WINBIND_INTERFACE_VERSION to 32 Pair-Programmed-With: Andreas Schneider <a...@samba.org> Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> Autobuild-User(master): Jeremy Allison <j...@samba.org> Autobuild-Date(master): Tue May 10 18:25:01 UTC 2022 on sn-devel-184 commit 8da5ec60a8ef4c99b33a6df204493ff82da864fc Author: Pavel Filipenský <pfili...@redhat.com> Date: Sun Sep 5 20:36:15 2021 +0200 winbind: enable "debug traceid" in main winbindd Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit 7c2d7930a36828b1564af9108e397a137324a458 Author: Pavel Filipenský <pfili...@redhat.com> Date: Sun Sep 5 22:18:11 2021 +0200 docs-xml: document "winbind debug traceid" in smb.conf Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit f2fa3706ad9f9de112607b20813053b98c5bbfe6 Author: Pavel Březina <pbrez...@redhat.com> Date: Wed Sep 1 16:05:37 2021 +0200 s3:winbindd add "'winbind debug traceid" support via tevent tracing Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit e48fc192d24a53db4209de262caec4d5b491952e Author: Pavel Filipenský <pfili...@redhat.com> Date: Sun May 8 21:06:13 2022 +0200 debug: add debug_traceid_set/get() interface Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit 7dbb527751a1c8a7e5dbde95959220fbcb0a28e3 Author: Pavel Filipenský <pfili...@redhat.com> Date: Sun May 8 21:09:04 2022 +0200 debug: fix trailing whitespace Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit 463f694d5c68141b161128944e46161d63e4569a Author: Pavel Filipenský <pfili...@redhat.com> Date: Tue May 10 13:06:53 2022 +0200 s3:lib: reset all tevent trace callbacks in reinit_after_fork() Signed-off-by: Pavel Filipenský <pfili...@redhat.com> With "tevent: add event trace api" we have now more callbacks to reset. Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> commit fa0430b21e4941bcea481320dcddc4c94c30ce88 Author: Pavel Filipenský <pfili...@redhat.com> Date: Tue May 10 13:06:05 2022 +0200 s3:lib: fix trailing whitespaces Signed-off-by: Pavel Filipenský <pfili...@redhat.com> Reviewed-by: Andreas Schneider <a...@samba.org> Reviewed-by: Jeremy Allison <j...@samba.org> ----------------------------------------------------------------------- Summary of changes: .../ldapdeletedn.xml => logging/debugtraceid.xml} | 12 +- lib/util/debug.c | 28 +++- lib/util/debug.h | 9 +- nsswitch/winbind_struct_protocol.h | 4 +- source3/lib/util.c | 39 +++--- source3/winbindd/winbindd.c | 15 +++ source3/winbindd/winbindd_dual.c | 13 ++ source3/winbindd/winbindd_traceid.c | 147 +++++++++++++++++++++ source3/winbindd/winbindd_traceid.h | 29 ++++ source3/winbindd/wscript_build | 1 + 10 files changed, 272 insertions(+), 25 deletions(-) copy docs-xml/smbdotconf/{ldap/ldapdeletedn.xml => logging/debugtraceid.xml} (51%) create mode 100644 source3/winbindd/winbindd_traceid.c create mode 100644 source3/winbindd/winbindd_traceid.h Changeset truncated at 500 lines: diff --git a/docs-xml/smbdotconf/ldap/ldapdeletedn.xml b/docs-xml/smbdotconf/logging/debugtraceid.xml similarity index 51% copy from docs-xml/smbdotconf/ldap/ldapdeletedn.xml copy to docs-xml/smbdotconf/logging/debugtraceid.xml index 47ffad80cbf..61a451da3e7 100644 --- a/docs-xml/smbdotconf/ldap/ldapdeletedn.xml +++ b/docs-xml/smbdotconf/logging/debugtraceid.xml @@ -1,13 +1,13 @@ -<samba:parameter name="ldap delete dn" +<samba:parameter name="winbind debug traceid" context="G" type="boolean" xmlns:samba="http://www.samba.org/samba/DTD/samba-doc"> <description> - <para> This parameter specifies whether a delete - operation in the ldapsam deletes the complete entry or only the attributes - specific to Samba. - </para> -</description> + <para> + With this boolean parameter enabled, the per request unique traceid + will be displayed in the debug header for winbind processes. + </para> +</description> <value type="default">no</value> </samba:parameter> diff --git a/lib/util/debug.c b/lib/util/debug.c index 4143cb6058a..42f408736ff 100644 --- a/lib/util/debug.c +++ b/lib/util/debug.c @@ -1796,11 +1796,21 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func) sizeof(state.header_str) - state.hs_len, ", class=%s", classname_table[cls]); + if (state.hs_len >= sizeof(state.header_str) - 1) { + goto full; + } } - if (state.hs_len >= sizeof(state.header_str) - 1) { - goto full; + if (debug_traceid_get() != 0) { + state.hs_len += snprintf(state.header_str + state.hs_len, + sizeof(state.header_str) - state.hs_len, + ", traceid=%" PRIu64, + debug_traceid_get()); + if (state.hs_len >= sizeof(state.header_str) - 1) { + goto full; + } } + state.header_str[state.hs_len] = ']'; state.hs_len++; if (state.hs_len < sizeof(state.header_str) - 1) { @@ -1884,3 +1894,17 @@ bool dbgtext(const char *format_str, ... ) return ret; } + +static uint64_t debug_traceid = 0; + +uint64_t debug_traceid_set(uint64_t id) +{ + uint64_t old_id = debug_traceid; + debug_traceid = id; + return old_id; +} + +uint64_t debug_traceid_get(void) +{ + return debug_traceid; +} diff --git a/lib/util/debug.h b/lib/util/debug.h index 7317c2f43c5..5f4833b0fcd 100644 --- a/lib/util/debug.h +++ b/lib/util/debug.h @@ -1,4 +1,4 @@ -/* +/* Unix SMB/CIFS implementation. SMB debug stuff Copyright (C) Andrew Tridgell 1992-1998 @@ -23,6 +23,7 @@ #ifndef _SAMBA_DEBUG_H #define _SAMBA_DEBUG_H +#include <stdint.h> #include <stdbool.h> #include <stddef.h> #include <stdarg.h> @@ -338,4 +339,10 @@ void debug_set_callback(void *private_ptr, debug_callback_fn fn); char *debug_get_ringbuf(void); size_t debug_get_ringbuf_size(void); +/* Explicitly set new traceid. The old id is returned. */ +uint64_t debug_traceid_set(uint64_t id); + +/* Get the current traceid. */ +uint64_t debug_traceid_get(void); + #endif /* _SAMBA_DEBUG_H */ diff --git a/nsswitch/winbind_struct_protocol.h b/nsswitch/winbind_struct_protocol.h index 87d10ae6e3e..ac0558c87c5 100644 --- a/nsswitch/winbind_struct_protocol.h +++ b/nsswitch/winbind_struct_protocol.h @@ -61,8 +61,9 @@ typedef char fstring[FSTRING_LEN]; * 29: added "authoritative" to response.data.auth * 30: added "validation_level" and "info6" to response.data.auth * 31: added "client_name" to the request + * 32: added "traceid" to the request */ -#define WINBIND_INTERFACE_VERSION 31 +#define WINBIND_INTERFACE_VERSION 32 /* Have to deal with time_t being 4 or 8 bytes due to structure alignment. On a 64bit Linux box, we have to support a constant structure size @@ -253,6 +254,7 @@ struct winbindd_request { uint32_t flags; /* flags relevant *only* to a given request */ fstring domain_name; /* name of domain for which the request applies */ char client_name[32]; /* The client process sending the request */ + uint64_t traceid; /* debug traceid is sent from parent to child */ union { fstring winsreq; /* WINS request */ diff --git a/source3/lib/util.c b/source3/lib/util.c index d39ad61db20..912ce1d3004 100644 --- a/source3/lib/util.c +++ b/source3/lib/util.c @@ -1,4 +1,4 @@ -/* +/* Unix SMB/CIFS implementation. Samba utility functions Copyright (C) Andrew Tridgell 1992-1998 @@ -455,7 +455,16 @@ NTSTATUS reinit_after_fork(struct messaging_context *msg_ctx, } if (ev_ctx != NULL) { + /* + * The parent can have different private data for the callbacks, + * which are gone in the child. Reset the callbacks to be safe. + */ tevent_set_trace_callback(ev_ctx, NULL, NULL); + tevent_set_trace_fd_callback(ev_ctx, NULL, NULL); + tevent_set_trace_signal_callback(ev_ctx, NULL, NULL); + tevent_set_trace_timer_callback(ev_ctx, NULL, NULL); + tevent_set_trace_immediate_callback(ev_ctx, NULL, NULL); + tevent_set_trace_queue_callback(ev_ctx, NULL, NULL); if (tevent_re_initialise(ev_ctx) != 0) { smb_panic(__location__ ": Failed to re-initialise event context"); } @@ -651,7 +660,7 @@ uid_t nametouid(const char *name) } /******************************************************************* - Convert a name to a gid_t if possible. Return -1 if not a group. + Convert a name to a gid_t if possible. Return -1 if not a group. ********************************************************************/ gid_t nametogid(const char *name) @@ -726,7 +735,7 @@ const char *readdirname(DIR *p) } /******************************************************************* - Utility function used to decide if the last component + Utility function used to decide if the last component of a path matches a (possibly wildcarded) entry in a namelist. ********************************************************************/ @@ -768,10 +777,10 @@ bool is_in_path(const char *name, name_compare_entry *namelist, bool case_sensit } /******************************************************************* - Strip a '/' separated list into an array of - name_compare_enties structures suitable for + Strip a '/' separated list into an array of + name_compare_enties structures suitable for passing to is_in_path(). We do this for - speed so we can pre-parse all the names in the list + speed so we can pre-parse all the names in the list and don't do it for each call to is_in_path(). We also check if the entry contains a wildcard to remove a potentially expensive call to mask_match @@ -789,7 +798,7 @@ void set_namearray(name_compare_entry **ppname_array, const char *namelist_in) (*ppname_array) = NULL; - if((namelist_in == NULL ) || ((namelist_in != NULL) && (*namelist_in == '\0'))) + if((namelist_in == NULL ) || ((namelist_in != NULL) && (*namelist_in == '\0'))) return; namelist = talloc_strdup(talloc_tos(), namelist_in); @@ -1262,7 +1271,7 @@ int str_checksum(const char *s) /***************************************************************** Zero a memory area then free it. Used to catch bugs faster. -*****************************************************************/ +*****************************************************************/ void zero_free(void *p, size_t size) { @@ -1272,7 +1281,7 @@ void zero_free(void *p, size_t size) /***************************************************************** Set our open file limit to a requested max and return the limit. -*****************************************************************/ +*****************************************************************/ int set_maxfiles(int requested_max) { @@ -1287,9 +1296,9 @@ int set_maxfiles(int requested_max) return requested_max; } - /* + /* * Set the fd limit to be real_max_open_files + MAX_OPEN_FUDGEFACTOR to - * account for the extra fd we need + * account for the extra fd we need * as well as the log files and standard * handles etc. Save the limit we want to set in case * we are running on an OS that doesn't support this limit (AIX) @@ -1309,7 +1318,7 @@ int set_maxfiles(int requested_max) support our default request of 10,000 open files. JRA. */ if(setrlimit(RLIMIT_NOFILE, &rlp)) { - DEBUG(3,("set_maxfiles: setrlimit for RLIMIT_NOFILE for %d max files failed with error %s\n", + DEBUG(3,("set_maxfiles: setrlimit for RLIMIT_NOFILE for %d max files failed with error %s\n", (int)rlp.rlim_max, strerror(errno) )); /* Set failed - restore original value from get. */ @@ -1323,7 +1332,7 @@ int set_maxfiles(int requested_max) saved_current_limit = rlp.rlim_cur = MIN(requested_max,rlp.rlim_max); if(setrlimit(RLIMIT_NOFILE, &rlp)) { - DEBUG(0,("set_maxfiles: setrlimit for RLIMIT_NOFILE for %d files failed with error %s\n", + DEBUG(0,("set_maxfiles: setrlimit for RLIMIT_NOFILE for %d files failed with error %s\n", (int)rlp.rlim_cur, strerror(errno) )); /* just guess... */ return saved_current_limit; @@ -1355,7 +1364,7 @@ int set_maxfiles(int requested_max) /***************************************************************** malloc that aborts with smb_panic on fail or zero size. - *****************************************************************/ + *****************************************************************/ void *smb_xmalloc_array(size_t size, unsigned int count) { @@ -1682,7 +1691,7 @@ int get_safe_SVAL(const char *buf_base, size_t buf_len, char *ptr, size_t off, i int get_safe_IVAL(const char *buf_base, size_t buf_len, char *ptr, size_t off, int failval) { /* - * Note we use off+3 here, not off+4 as IVAL accesses + * Note we use off+3 here, not off+4 as IVAL accesses * ptr[0] ptr[1] ptr[2] ptr[3] NOT ptr[4]. */ if (!is_offset_safe(buf_base, buf_len, ptr, off+3)) { diff --git a/source3/winbindd/winbindd.c b/source3/winbindd/winbindd.c index af596319579..710df3c74d5 100644 --- a/source3/winbindd/winbindd.c +++ b/source3/winbindd/winbindd.c @@ -52,6 +52,7 @@ #include "rpc_server/rpc_config.h" #include "lib/global_contexts.h" #include "source3/lib/substitute.h" +#include "winbindd_traceid.h" #undef DBGC_CLASS #define DBGC_CLASS DBGC_WINBIND @@ -421,7 +422,18 @@ static struct tevent_req *process_request_send( enum winbindd_cmd cmd = cli_state->request->cmd; size_t i; bool ok; + static uint64_t request_index = 1; + /* + * debug traceid values: + * 0 .. inactive + * 1 .. not processing a winbind request, but in other code (timers) + * >=2 .. winbind request processing + */ + if (debug_traceid_get() != 0) { + request_index = ++request_index == 0 ? 2 : request_index; + debug_traceid_set(request_index); + } req = tevent_req_create(mem_ctx, &state, struct process_request_state); if (req == NULL) { @@ -1623,6 +1635,9 @@ int main(int argc, const char **argv) exit_daemon("Winbindd reinit_after_fork() failed", map_errno_from_nt_status(status)); } + if (lp_winbind_debug_traceid()) { + winbind_debug_traceid_setup(global_event_context()); + } ok = initialize_password_db(true, global_event_context()); if (!ok) { exit_daemon("Failed to initialize passdb backend! " diff --git a/source3/winbindd/winbindd_dual.c b/source3/winbindd/winbindd_dual.c index d517b83a3e2..b880feaac13 100644 --- a/source3/winbindd/winbindd_dual.c +++ b/source3/winbindd/winbindd_dual.c @@ -33,6 +33,7 @@ #include "nsswitch/wb_reqtrans.h" #include "secrets.h" #include "../lib/util/select.h" +#include "winbindd_traceid.h" #include "../libcli/security/security.h" #include "system/select.h" #include "messages.h" @@ -222,6 +223,8 @@ struct tevent_req *wb_child_request_send(TALLOC_CTX *mem_ctx, return tevent_req_post(req, ev); } + state->request->traceid = debug_traceid_get(); + if (request->extra_data.data != NULL) { state->request->extra_data.data = talloc_memdup( state->request, @@ -1625,6 +1628,7 @@ static void child_handler(struct tevent_context *ev, struct tevent_fd *fde, struct child_handler_state *state = (struct child_handler_state *)private_data; NTSTATUS status; + uint64_t parent_traceid; /* fetch a request from the main daemon */ status = child_read_request(state->cli.sock, state->cli.request); @@ -1634,6 +1638,10 @@ static void child_handler(struct tevent_context *ev, struct tevent_fd *fde, _exit(0); } + /* read traceid from request */ + parent_traceid = state->cli.request->traceid; + debug_traceid_set(parent_traceid); + DEBUG(4,("child daemon request %d\n", (int)state->cli.request->cmd)); @@ -1747,6 +1755,11 @@ static bool fork_domain_child(struct winbindd_child *child) status = winbindd_reinit_after_fork(child, child->logfilename); + /* setup callbacks again, one of them is removed in reinit_after_fork */ + if (lp_winbind_debug_traceid()) { + winbind_debug_traceid_setup(global_event_context()); + } + nwritten = sys_write(state.cli.sock, &status, sizeof(status)); if (nwritten != sizeof(status)) { DEBUG(1, ("fork_domain_child: Could not write status: " diff --git a/source3/winbindd/winbindd_traceid.c b/source3/winbindd/winbindd_traceid.c new file mode 100644 index 00000000000..acf16bec3a4 --- /dev/null +++ b/source3/winbindd/winbindd_traceid.c @@ -0,0 +1,147 @@ +/* + 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 "lib/util/debug.h" +#include "winbindd_traceid.h" +#include "tevent.h" + +static void debug_traceid_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 traceid id when the event is created. */ + tevent_fd_set_tag(fde, debug_traceid_get()); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the traceid id when a handler is being called. */ + debug_traceid_set(tevent_fd_get_tag(fde)); + break; + default: + /* Do nothing. */ + break; + } +} + +static void debug_traceid_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 traceid id when the event is created. */ + tevent_signal_set_tag(se, debug_traceid_get()); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the traceid id when a handler is being called. */ + debug_traceid_set(tevent_signal_get_tag(se)); + break; + default: + /* Do nothing. */ + break; + } +} + +static void debug_traceid_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 traceid id when the event is created. */ + tevent_timer_set_tag(timer, debug_traceid_get()); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the traceid id when a handler is being called. */ + debug_traceid_set(tevent_timer_get_tag(timer)); + break; + default: + /* Do nothing. */ + break; + } +} + +static void debug_traceid_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 traceid id when the event is created. */ + tevent_immediate_set_tag(im, debug_traceid_get()); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the traceid id when a handler is being called. */ + debug_traceid_set(tevent_immediate_get_tag(im)); + break; + default: + /* Do nothing. */ + break; + } +} + +static void debug_traceid_trace_queue(struct tevent_queue_entry *qe, + enum tevent_event_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_EVENT_TRACE_ATTACH: + /* Assign the current traceid id when the event is created. */ + tevent_queue_entry_set_tag(qe, debug_traceid_get()); + break; + case TEVENT_EVENT_TRACE_BEFORE_HANDLER: + /* Set the traceid id when a handler is being called. */ + debug_traceid_set(tevent_queue_entry_get_tag(qe)); + break; + default: + /* Do nothing. */ + break; + } +} + +static void debug_traceid_trace_loop(enum tevent_trace_point point, + void *private_data) +{ + switch (point) { + case TEVENT_TRACE_AFTER_LOOP_ONCE: + /* Reset traceid id when we got back to the loop. An event handler + * that set traceid id was fired. This tracepoint represents a place + * after the event handler was finished, we need to restore traceid + * id to 1 (out of request). 0 means not initialized. + */ + debug_traceid_set(1); + break; + default: + /* Do nothing. */ + break; + } +} + +void winbind_debug_traceid_setup(struct tevent_context *ev) +{ + tevent_set_trace_callback(ev, debug_traceid_trace_loop, NULL); + tevent_set_trace_fd_callback(ev, debug_traceid_trace_fde, NULL); + tevent_set_trace_signal_callback(ev, debug_traceid_trace_signal, NULL); -- Samba Shared Repository