[SCM] Samba Shared Repository - branch master updated

Andreas Schneider asn at samba.org
Thu Jan 26 15:08:01 UTC 2023


The branch, master has been updated
       via  c2f8fde9f30 s3:test: Test winbind call depth trace
       via  51d559d8f49 s3:winbind: Move tevent_req_create() before debug macros to have the right call depth
       via  4b6e8e1c117 s3:winbind: Deactivate call depth tracking in child winbindd
       via  a6c1211504b s3:winbind: Activate the call depth tracking in main winbindd
       via  3b1b37b1cf8 debug: Call depth: Indent the debug text
       via  7ba3b1b09de debug: Call depth: Print ", depth=..." in the debug header
       via  e3e687b659a debug: Call depth: Interface
       via  13d2db03973 debug: Fix whitespaces in debug.c
       via  c7a3b256291 selftest: Update devel_env.sh for SAMBA_DCERPCD_DONT_LOG_STDOUT=1
       via  fd7187daed8 s3:tests: Add support for SMBD_DONT_LOG_STDOUT=1 in test_chdir_cache.sh
      from  56c6f0b6d64 selftest: Only run samba.tests.smb3unix in developer mode

https://git.samba.org/?p=samba.git;a=shortlog;h=master


- Log -----------------------------------------------------------------
commit c2f8fde9f308b0962cbb4cfa4fffda8c770e14db
Author: Pavel Filipenský <pfilipensky at samba.org>
Date:   Wed Jan 25 02:01:22 2023 +0100

    s3:test: Test winbind call depth trace
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>
    
    Autobuild-User(master): Andreas Schneider <asn at cryptomilk.org>
    Autobuild-Date(master): Thu Jan 26 15:07:57 UTC 2023 on atb-devel-224

commit 51d559d8f498d9941b50953bfe33d9f4110c2c96
Author: Pavel Filipenský <pfilipensky at samba.org>
Date:   Mon Sep 12 16:06:09 2022 +0200

    s3:winbind: Move tevent_req_create() before debug macros to have the right call depth
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit 4b6e8e1c1178bd0e3177b12b22d60c7e3c44c1af
Author: Pavel Filipenský <pfilipen at redhat.com>
Date:   Fri Jun 17 18:03:35 2022 +0200

    s3:winbind: Deactivate call depth tracking in child winbindd
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit a6c1211504bbfc84cae7545539ba38e35417dc42
Author: Pavel Filipenský <pfilipen at redhat.com>
Date:   Thu Jun 16 17:56:39 2022 +0200

    s3:winbind: Activate the call depth tracking in main winbindd
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit 3b1b37b1cf8f3599f2970cea1d9f0daa36afe4af
Author: Pavel Filipenský <pfilipensky at samba.org>
Date:   Fri Aug 26 11:42:42 2022 +0200

    debug: Call depth: Indent the debug text
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit 7ba3b1b09de327f77ee11b1c5ba3a77260ce2342
Author: Pavel Filipenský <pfilipensky at samba.org>
Date:   Fri Aug 26 11:42:42 2022 +0200

    debug: Call depth: Print ", depth=..." in the debug header
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit e3e687b659ac0d60a0e1f0775ab3cc7181b3cc29
Author: Pavel Filipenský <pfilipensky at samba.org>
Date:   Fri Aug 26 11:41:44 2022 +0200

    debug: Call depth: Interface
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit 13d2db03973c4e26b2cff0925faab785a3c12494
Author: Pavel Filipenský <pfilipen at redhat.com>
Date:   Fri Jun 10 15:35:53 2022 +0200

    debug: Fix whitespaces in debug.c
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15287
    
    Signed-off-by: Pavel Filipenský <pfilipensky at samba.org>
    Reviewed-by: Andreas Schneider <asn at samba.org>

commit c7a3b256291dd7d18d67b7f909a00fbd2103e1b8
Author: Andreas Schneider <asn at samba.org>
Date:   Wed Jan 25 17:26:17 2023 +0100

    selftest: Update devel_env.sh for SAMBA_DCERPCD_DONT_LOG_STDOUT=1
    
    Signed-off-by: Andreas Schneider <asn at samba.org>
    Reviewed-by: Pavel Filipenský <pfilipen at redhat.com>

commit fd7187daed85f4ea51762c029ae8ef3fa893b2fb
Author: Andreas Schneider <asn at samba.org>
Date:   Mon Jan 23 10:21:33 2023 +0100

    s3:tests: Add support for SMBD_DONT_LOG_STDOUT=1 in test_chdir_cache.sh
    
    BUG: https://bugzilla.samba.org/show_bug.cgi?id=15291
    
    Signed-off-by: Andreas Schneider <asn at samba.org>
    Reviewed-by: Ralph Boehme <slow at samba.org>

-----------------------------------------------------------------------

Summary of changes:
 lib/util/debug.c                                   |  42 +++++++-
 lib/util/debug.h                                   |   2 +
 selftest/devel_env.sh                              |   1 +
 selftest/target/Samba3.pm                          |   1 +
 source3/script/tests/test_chdir_cache.sh           |  16 ++-
 .../script/tests/test_winbind_call_depth_trace.sh  | 113 +++++++++++++++++++++
 source3/selftest/tests.py                          |   9 +-
 source3/winbindd/wb_lookupsids.c                   |  10 +-
 source3/winbindd/wb_sids2xids.c                    |   6 +-
 source3/winbindd/winbindd.c                        |   2 +
 source3/winbindd/winbindd_dual.c                   |   6 ++
 11 files changed, 193 insertions(+), 15 deletions(-)
 create mode 100755 source3/script/tests/test_winbind_call_depth_trace.sh


Changeset truncated at 500 lines:

diff --git a/lib/util/debug.c b/lib/util/debug.c
index 517157ef6a8..43d5151fbab 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -1598,6 +1598,17 @@ static void bufr_print( void )
 	format_pos = 0;
 }
 
+/*
+ * If set (by tevent_thread_call_depth_set()) to value > 0, debug code will use
+ * it for the trace indentation.
+ */
+static size_t debug_call_depth = 0;
+
+size_t *debug_call_depth_addr(void)
+{
+	return &debug_call_depth;
+}
+
 /***************************************************************************
  Format the debug message text.
 
@@ -1624,8 +1635,21 @@ static void format_debug_text( const char *msg )
 	for( i = 0; msg[i]; i++ ) {
 		/* Indent two spaces at each new line. */
 		if(timestamp && 0 == format_pos) {
+			/* Limit the maximum indentation to 20 levels */
+			size_t depth = MIN(20, debug_call_depth);
 			format_bufr[0] = format_bufr[1] = ' ';
 			format_pos = 2;
+			/*
+			 * Indent by four spaces for each depth level,
+			 * but only if the current debug level is >= 8.
+			 */
+			if (depth > 0 && debuglevel_get() >= 8 &&
+			    format_pos + 4 * depth < FORMAT_BUFR_SIZE) {
+				memset(&format_bufr[format_pos],
+				       ' ',
+				       4 * depth);
+				format_pos += 4 * depth;
+			}
 		}
 
 		/* If there's room, copy the character to the format buffer. */
@@ -1841,6 +1865,16 @@ bool dbghdrclass(int level, int cls, const char *location, const char *func)
 		}
 	}
 
+	if (debug_call_depth > 0) {
+		state.hs_len += snprintf(state.header_str + state.hs_len,
+					 sizeof(state.header_str) - state.hs_len,
+					 ", depth=%zu",
+					 debug_call_depth);
+		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) {
@@ -1929,12 +1963,12 @@ 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 old_id = debug_traceid;
+	debug_traceid = id;
+	return old_id;
 }
 
 uint64_t debug_traceid_get(void)
 {
-    return debug_traceid;
+	return debug_traceid;
 }
diff --git a/lib/util/debug.h b/lib/util/debug.h
index f58bb005145..4bbfa05df65 100644
--- a/lib/util/debug.h
+++ b/lib/util/debug.h
@@ -378,4 +378,6 @@ uint64_t debug_traceid_set(uint64_t id);
 /* Get the current traceid. */
 uint64_t debug_traceid_get(void);
 
+size_t *debug_call_depth_addr(void);
+
 #endif /* _SAMBA_DEBUG_H */
diff --git a/selftest/devel_env.sh b/selftest/devel_env.sh
index d1c0736ab09..bbb99e0a250 100644
--- a/selftest/devel_env.sh
+++ b/selftest/devel_env.sh
@@ -9,3 +9,4 @@ export TDB_NO_FSYNC=1
 export NMBD_DONT_LOG_STDOUT=1
 export SMBD_DONT_LOG_STDOUT=1
 export WINBINDD_DONT_LOG_STDOUT=1
+export SAMBA_DCERPCD_DONT_LOG_STDOUT=1
diff --git a/selftest/target/Samba3.pm b/selftest/target/Samba3.pm
index 6f93694f1b3..f9346ae812e 100755
--- a/selftest/target/Samba3.pm
+++ b/selftest/target/Samba3.pm
@@ -2854,6 +2854,7 @@ sub provision($$)
 	lock directory = $lockdir
 	log file = $logdir/log.\%m
 	log level = $server_log_level
+	winbind debug traceid = yes
 	debug pid = yes
         max log size = 0
 
diff --git a/source3/script/tests/test_chdir_cache.sh b/source3/script/tests/test_chdir_cache.sh
index c649d2b07b3..11967180d35 100755
--- a/source3/script/tests/test_chdir_cache.sh
+++ b/source3/script/tests/test_chdir_cache.sh
@@ -9,7 +9,7 @@
 
 if [ $# -lt 5 ]; then
 	echo Usage: test_chdir_user.sh \
-		--configfile=SERVERCONFFILE SMBCLIENT SMBCONTROL SERVER SHARE
+		--configfile=SERVERCONFFILE SMBCLIENT SMBCONTROL SERVER SHARE PREFIX TESTENV
 	exit 1
 fi
 
@@ -23,6 +23,12 @@ SERVER=$1
 shift 1
 SHARE=$1
 shift 1
+PREFIX=${1}
+shift 1
+TESTENV=${1}
+shift 1
+
+PREFIX_ABS="$(readlink -f "${PREFIX}")"
 
 # Do not let deprecated option warnings muck this up
 SAMBA_DEPRECATED_SUPPRESS=1
@@ -30,8 +36,6 @@ export SAMBA_DEPRECATED_SUPPRESS
 
 conf_dir=$(dirname ${SERVERCONFFILE})
 
-log_file=${conf_dir}/../smbd_test.log
-
 error_inject_conf=${conf_dir}/error_inject.conf
 rm -f ${error_inject_conf}
 
@@ -52,6 +56,12 @@ ${SMBCLIENT} //${SERVER}/${SHARE} ${CONF} -U${USER}%${PASSWORD} \
 	<smbclient-stdin >smbclient-stdout 2>smbclient-stderr &
 CLIENT_PID=$!
 
+log_file="${PREFIX_ABS}/${TESTENV}/smbd_test.log"
+# Add support for "SMBD_DONT_LOG_STDOUT=1"
+if [ -r "${PREFIX_ABS}/${TESTENV}/logs/log.smbd" ]; then
+	log_file="${PREFIX_ABS}/${TESTENV}/logs/log.smbd"
+fi
+
 # Count the number of chdir_current_service: vfs_ChDir.*failed: Permission denied
 # errors that are already in the log (should be zero).
 num_errs=$(grep "chdir_current_service: vfs_ChDir.*failed: Permission denied" ${log_file} | wc -l)
diff --git a/source3/script/tests/test_winbind_call_depth_trace.sh b/source3/script/tests/test_winbind_call_depth_trace.sh
new file mode 100755
index 00000000000..6d978beca8f
--- /dev/null
+++ b/source3/script/tests/test_winbind_call_depth_trace.sh
@@ -0,0 +1,113 @@
+#!/bin/sh
+
+# Copyright (c) Pavel Filipenský <pfilipensky at samba.org>
+# License: GPLv3
+
+if [ $# -lt 4 ]; then
+	echo "Usage: test_winbind_call_depth_trace SMBCONTROL CONFIGURATION PREFIX TESTENV"
+	exit 1
+fi
+
+SMBCONTROL="${1}"
+CONFIGURATION=${2}
+PREFIX="${3}"
+TESTENV="${4}"
+shift 4
+
+incdir=$(dirname "$0")/../../../testprogs/blackbox
+. "$incdir"/subunit.sh
+
+failed=0
+
+PREFIX_ABS="$(readlink -f "${PREFIX}")"
+# Strip from TESTENV the ':local' if present
+TESTENV_SUBDIR=${TESTENV%:*}
+
+LOGFILE="${PREFIX_ABS}/${TESTENV_SUBDIR}/logs/log.winbindd"
+# Add support for "WINBINDD_DONT_LOG_STDOUT=1"
+if [ ! -r "${LOGFILE}" ]; then
+	TEST_LOGFILE="${PREFIX_ABS}/${TESTENV_SUBDIR}/winbindd_test.log"
+	subunit_start_test "test winbind call depth trace"
+	subunit_skip_test "test winbind call depth trace" <<EOF
+Test is skipped, we need $LOGFILE but have only $TEST_LOGFILE which is missing debug headers (they are not printed to stdout).
+EOF
+	exit 0
+fi
+
+saved_level=1
+
+get_winbind_loglevel()
+{
+	s1=$(${SMBCONTROL} "${CONFIGURATION}" winbind debuglevel)
+	# We need to get the all level from output like this:
+	# "PID 664474: all:1 tdb:1 printdrivers:1  lanman:1 smb:1 rpc_parse:1 rpc_srv:1 rpc_cli:1 passdb:1 sam:1..."
+	# 1. remove PID 664474:
+	s2=${s1#PID*: }
+	# "all:1 tdb:1 printdrivers:1  lanman:1 smb:1 rpc_parse:1 rpc_srv:1 rpc_cli:1 passdb"
+	# 2. remove " tdb:1 printdrivers:1 ..."
+	s3=${s2%% *}
+	# "all:1"
+	# 3. remove "all:"
+	saved_level=${s3#all:}
+}
+
+# Example of trace line
+# [2023/01/25 00:20:33.307038,  5, pid=535581, effective(0, 0), real(0, 0), class=winbind, traceid=78, depth=4] ../../source3/winbindd/wb_group_members.c:310(wb_group_members_send)
+test_winbind_call_depth_trace()
+{
+	get_winbind_loglevel
+
+	# If loglevel < 10, set it to 10.
+	if [ "$saved_level" -lt 10 ]; then
+		${SMBCONTROL}  "${CONFIGURATION}" winbind debug 10
+	fi
+
+	COUNT1=$(grep -c wb_group_members_send "$LOGFILE")
+
+	id ADDOMAIN/alice
+	ret=$?
+
+	# Restore loglevel, if it was changed.
+	if [ "$saved_level" -lt 10 ]; then
+		${SMBCONTROL} "${CONFIGURATION}" winbind debug "$saved_level"
+	fi
+
+	if [ $ret != 0 ]; then
+		echo "Command 'id ADDOMAIN/alice' failed!"
+		return 1
+	fi
+
+	# Check that there are more lines with wb_group_members_send
+	COUNT2=$(grep -c wb_group_members_send "$LOGFILE")
+	if [ "$COUNT1" -eq "$COUNT2" ]; then
+		echo "The number of the trace lines in $LOGFILE has not increased."
+		return 1
+	fi
+
+	# Test that the depth of last line with 'wb_group_members_send' is: depth=4
+	COUNT3=$(grep wb_group_members_send "$LOGFILE" | tail -1 | grep -c depth=4)
+	if [ "$COUNT3" -ne 1 ]; then
+		echo "The last line with wb_group_members_send should have depth=4."
+		return 1
+	fi
+
+	# Test that the indentation of the line below last 'wb_group_members_send' is indented by 2+4*4 spaces:
+	COUNT4=$(grep -A1 wb_group_members_send "$LOGFILE" | tail -1| grep -c '^                  WB command group_members start')
+	if [ "$COUNT4" -ne 1 ]; then
+		echo "The line after the last line with wb_group_members_send should be indented by 18 spaces."
+		return 1
+	fi
+
+	return 0
+}
+
+case ${TESTENV} in
+ad_member*)
+	;;
+*)
+	echo "Test is for ad_member only, but called for ${TESTENV}." | subunit_fail_test "test winbind call depth trace"
+	exit 1;
+esac
+
+testit "test winbind call depth trace"  test_winbind_call_depth_trace || failed=$((failed + 1))
+testok "$0" "$failed"
diff --git a/source3/selftest/tests.py b/source3/selftest/tests.py
index 187f3ccd9c0..76b8ad980ee 100755
--- a/source3/selftest/tests.py
+++ b/source3/selftest/tests.py
@@ -608,6 +608,11 @@ plantestsuite("samba3.wbinfo_user_info", env,
                             "nsswitch/tests/test_wbinfo_user_info.sh"),
                '$DOMAIN', '$REALM', '$DOMAIN', 'alice', 'alice', 'jane', 'jane.doe', env])
 
+plantestsuite("samba3.winbind_call_depth_trace", env,
+              [os.path.join(srcdir(),
+                            "source3/script/tests/test_winbind_call_depth_trace.sh"),
+               smbcontrol, configuration, '$PREFIX', env])
+
 env = "fl2008r2dc:local"
 plantestsuite("samba3.wbinfo_user_info", env,
               [os.path.join(srcdir(),
@@ -1402,7 +1407,9 @@ plantestsuite("samba3.blackbox.chdir-cache", "simpleserver:local",
                os.path.join(bindir(), "smbclient"),
                os.path.join(bindir(), "smbcontrol"),
                '$SERVER_IP',
-               "error_inject"])
+               "error_inject",
+               '$PREFIX',
+               'simpleserver'])
 
 plantestsuite("samba3.blackbox.netfileenum", "simpleserver:local",
               [os.path.join(samba3srcdir,
diff --git a/source3/winbindd/wb_lookupsids.c b/source3/winbindd/wb_lookupsids.c
index d0259119731..3473f7a1c97 100644
--- a/source3/winbindd/wb_lookupsids.c
+++ b/source3/winbindd/wb_lookupsids.c
@@ -116,6 +116,11 @@ struct tevent_req *wb_lookupsids_send(TALLOC_CTX *mem_ctx,
 	struct wb_lookupsids_state *state;
 	uint32_t i;
 
+	req = tevent_req_create(mem_ctx, &state, struct wb_lookupsids_state);
+	if (req == NULL) {
+		return NULL;
+	}
+
 	D_INFO("WB command lookupsids start.\nLooking up %"PRIu32" SID(s)\n",
 	       num_sids);
 	if (CHECK_DEBUGLVL(DBGLVL_INFO)) {
@@ -125,10 +130,7 @@ struct tevent_req *wb_lookupsids_send(TALLOC_CTX *mem_ctx,
 			       i, dom_sid_str_buf(&sids[i], &buf));
 		}
 	}
-	req = tevent_req_create(mem_ctx, &state, struct wb_lookupsids_state);
-	if (req == NULL) {
-		return NULL;
-	}
+
 	state->ev = ev;
 	state->sids = sids;
 	state->num_sids = num_sids;
diff --git a/source3/winbindd/wb_sids2xids.c b/source3/winbindd/wb_sids2xids.c
index 9a3507ba702..f0f6c23fc20 100644
--- a/source3/winbindd/wb_sids2xids.c
+++ b/source3/winbindd/wb_sids2xids.c
@@ -81,15 +81,15 @@ struct tevent_req *wb_sids2xids_send(TALLOC_CTX *mem_ctx,
 	uint32_t i;
 	uint32_t num_valid = 0;
 
-	D_INFO("WB command sids2xids start.\n"
-	       "Resolving %"PRIu32" SID(s).\n", num_sids);
-
 	req = tevent_req_create(mem_ctx, &state,
 				struct wb_sids2xids_state);
 	if (req == NULL) {
 		return NULL;
 	}
 
+	D_INFO("WB command sids2xids start.\n"
+	       "Resolving %"PRIu32" SID(s).\n", num_sids);
+
 	state->ev = ev;
 
 	state->num_sids = num_sids;
diff --git a/source3/winbindd/winbindd.c b/source3/winbindd/winbindd.c
index 50dc6d6bd92..16b9eebeb89 100644
--- a/source3/winbindd/winbindd.c
+++ b/source3/winbindd/winbindd.c
@@ -440,6 +440,7 @@ static struct tevent_req *process_request_send(
 	if (req == NULL) {
 		return NULL;
 	}
+	tevent_thread_call_depth_start(req);
 	state->cli_state = cli_state;
 	state->ev = ev;
 
@@ -1636,6 +1637,7 @@ int main(int argc, const char **argv)
 
 	if (lp_winbind_debug_traceid()) {
 		winbind_debug_traceid_setup(global_event_context());
+		tevent_thread_call_depth_activate(debug_call_depth_addr());
 	}
 	ok = initialize_password_db(true, global_event_context());
 	if (!ok) {
diff --git a/source3/winbindd/winbindd_dual.c b/source3/winbindd/winbindd_dual.c
index 8cb59b2f752..d9c32b10072 100644
--- a/source3/winbindd/winbindd_dual.c
+++ b/source3/winbindd/winbindd_dual.c
@@ -1742,6 +1742,12 @@ static bool fork_domain_child(struct winbindd_child *child)
 	state.cli.sock = fdpair[0];
 	close(fdpair[1]);
 
+	/* Reset traceid and deactivate call_depth tracking */
+	if (lp_winbind_debug_traceid()) {
+		debug_traceid_set(1);
+		tevent_thread_call_depth_deactivate();
+	}
+
 	status = winbindd_reinit_after_fork(child, child->logfilename);
 
 	/* setup callbacks again, one of them is removed in reinit_after_fork */


-- 
Samba Shared Repository



More information about the samba-cvs mailing list