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ý <pfilipen...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
Autobuild-User(master): Andreas Schneider <a...@cryptomilk.org>
Autobuild-Date(master): Thu Jan 26 15:07:57 UTC 2023 on atb-devel-224
commit 51d559d8f498d9941b50953bfe33d9f4110c2c96
Author: Pavel Filipenský <pfilipen...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit 4b6e8e1c1178bd0e3177b12b22d60c7e3c44c1af
Author: Pavel Filipenský <pfili...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit a6c1211504bbfc84cae7545539ba38e35417dc42
Author: Pavel Filipenský <pfili...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit 3b1b37b1cf8f3599f2970cea1d9f0daa36afe4af
Author: Pavel Filipenský <pfilipen...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit 7ba3b1b09de327f77ee11b1c5ba3a77260ce2342
Author: Pavel Filipenský <pfilipen...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit e3e687b659ac0d60a0e1f0775ab3cc7181b3cc29
Author: Pavel Filipenský <pfilipen...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit 13d2db03973c4e26b2cff0925faab785a3c12494
Author: Pavel Filipenský <pfili...@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ý <pfilipen...@samba.org>
Reviewed-by: Andreas Schneider <a...@samba.org>
commit c7a3b256291dd7d18d67b7f909a00fbd2103e1b8
Author: Andreas Schneider <a...@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 <a...@samba.org>
Reviewed-by: Pavel Filipenský <pfili...@redhat.com>
commit fd7187daed85f4ea51762c029ae8ef3fa893b2fb
Author: Andreas Schneider <a...@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 <a...@samba.org>
Reviewed-by: Ralph Boehme <s...@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ý <pfilipen...@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
