Hi,
the attached patches are the first self-contained part of my performance
work. Using them, I analyzed the performance of 'id' as the worst-case,
then realized most of the issues are around processing and storing large
groups. The results gathered using these scripts are in fact the base of
the improvements documented at:
https://fedorahosted.org/sssd/wiki/DesignDocs/OneFourteenPerformanceImprovements
I tried to add descriptive commit messages to the patches so that hopefully
all the info is in those commit messages. We will probably add more probes
into different areas of code, but these are the ones that I already haven't
modified for weeks, so I think it should be safe to merge them.
The probes are enabled in our RPMs and I would encourage downstreams to
enable them as well. There is virtually no cost of having the probes
compiled in by default and the benefit would be that admins can run them
to see what are the bottlenecks in their environment. I was also
wondering if it makes sense to add a generic back-end-request tracking
probes and an associated script, but since the data provider is being
re-factored at the moment, I think it would be better to land the DP
changes first.
The reason I split the sysdb probes into several commits (unlike the LDAP
probes) is that I think in future, we can use these commits as a
reference for adding more probes to different areas of SSSD.
CI: http://sssd-ci.duckdns.org/logs/job/42/99/summary.html
(BTW, thanks to Lukas for helping me a lot with the build failures on
#sssd last week)
>From 60d21413ee5b72ed3d732f7a2fbf72a8061040fd Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Tue, 1 Dec 2015 23:23:33 +0100
Subject: [PATCH 01/10] UTIL: Add a PROBE macro into probes.h
The macros are inspired by very similar macros in libvirt code.
Adds a macro PROBE that can be used by SSSD developers to add systemtap
marks to code. These marks, when coupled with a location in a binary can
be in turn used to call probes. The mark can be called like this:
PROBE(PROBE_NAME, arguments)
This is cleaner than using the SSSD_$(PROBE_NAME) directly as it
directly shows that a probe is being called at that place.
If the systemtap tracing is disabled, they would expand to an empty macro. If
the systemtap tracing is enabled, the systemtap probe will be called.
The overhead of calling the probes is close to zero. As one of the
systemtap developers explained to me:
"""
STAP_PROBE() macros cost apprx. one nop in the executable, so apprx.
no cost at all. The more the merrier. Only when activated by a
stap script do we generally think of it like a microsecond of time.
"""
The probe arguments can be used in the probes to be printed or passed
on to functions. There was an issue in case a string argument was NULL.
This commit adds a helper macro to deal with NULL-strings as if they were
empty ("").
This file would be included by any source file that wants to call the
PROBE() macro.
---
Makefile.am | 1 +
src/util/probes.h | 44 ++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 45 insertions(+)
create mode 100644 src/util/probes.h
diff --git a/Makefile.am b/Makefile.am
index
7161bef3c9b47db92a390220e3f285c7b5d2d812..17c7156e8ec7143a21d8a7e660c1d291240da8e6
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -679,6 +679,7 @@ dist_noinst_HEADERS = \
src/tests/cmocka/test_utils.h \
src/tools/common/sss_tools.h \
src/tools/common/sss_colondb.h \
+ src/util/probes.h \
$(NULL)
diff --git a/src/util/probes.h b/src/util/probes.h
new file mode 100644
index
0000000000000000000000000000000000000000..349f29086e86a51b4551f09f542d0f45bf6f1aae
--- /dev/null
+++ b/src/util/probes.h
@@ -0,0 +1,44 @@
+/*
+ Copyright (C) 2015 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 __PROBES_H_
+#define __PROBES_H_
+
+#ifdef HAVE_SYSTEMTAP
+
+/* Probe expansion inspired by libvirt */
+#define PROBE_EXPAND(NAME, ...) NAME(__VA_ARGS__)
+
+#define PROBE(NAME, ...) do { \
+ if (SSSD_ ## NAME ## _ENABLED()) { \
+ PROBE_EXPAND(SSSD_ ## NAME, \
+ __VA_ARGS__); \
+ } \
+} while(0);
+
+/* Systemtap doesn't handle copying NULL strings well */
+#define PROBE_SAFE_STR(s) ((s) ? (s) : "")
+
+#else
+
+/* No systemtap, define empty macros */
+#define PROBE(NAME, ...) do { \
+} while(0);
+
+#endif
+
+#endif /* __PROBES_H_ */
--
2.4.11
>From 873178275930d201248d68c18cde5f330a05fd3d Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Mon, 29 Feb 2016 13:05:59 +0100
Subject: [PATCH 02/10] BUILD: Add build infrastructure for systemtap scripts
Adds infrastructure that generatest the probes.h and probes.o from the
dtrace probes.d file. The probes.d file is empty except for the provider
name in this commit, its content will be added with later commits that
actually add some content. The probes.d file is always distributed in
the tarball so that distributions can optionally enable systemtap
support.
The generation is done using the "dtrace" command because the probes.d file
is compatible with the Solaris dtrace format. Please see "man 1 dtrace"
for more information on the dtrace format and the command line tool.
In order to make libtool happy, a fake libtool object is generated. This
hunk was taken from the libvirt code.
The AM_V_GEN macro is used to make the build compatible with the silent
build configuration.
To enable systemtap probing, configure sssd with:
--enable-systemtap
In order to do so, the 'dtrace' command-line utility must be installed.
On Fedora and RHEL, this package is installed as part of the
"systemtap-sdt-devel" package.
You'll also want the 'systemtap' package installed as well as the matching
versions of kernel-devel and kernel-debuginfo on your machine.
---
Makefile.am | 43 +++++++++++++++++++++++++++++++++++++++++--
configure.ac | 4 ++++
src/external/systemtap.m4 | 35 +++++++++++++++++++++++++++++++++++
src/systemtap/sssd_probes.d | 2 ++
src/tests/cwrap/Makefile.am | 6 ++++++
src/util/probes.h | 2 ++
6 files changed, 90 insertions(+), 2 deletions(-)
create mode 100644 src/external/systemtap.m4
create mode 100644 src/systemtap/sssd_probes.d
diff --git a/Makefile.am b/Makefile.am
index
17c7156e8ec7143a21d8a7e660c1d291240da8e6..0cdfd54e7e7bc685e712b2ff01cc5c551f1c05cf
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -12,6 +12,8 @@ DISTCHECK_CONFIGURE_FLAGS =
--with-ldb-lib-dir="$$dc_install_base"/lib/ldb \
--enable-all-experimental-features \
$(extra_distcheck_flags) \
$(AUX_DISTCHECK_CONFIGURE_FLAGS)
+CLEANFILES = $(NULL)
+BUILT_SOURCES = $(NULL)
SUBDIRS = po
@@ -401,6 +403,7 @@ dist_noinst_DATA = \
contrib/ci/sssd.supp \
src/tests/cmocka/p11_nssdb/cert9.db \
src/tests/cmocka/p11_nssdb/key4.db \
+ $(SYSTEMTAP_PROBES) \
$(NULL)
###############################
@@ -892,6 +895,9 @@ libsss_util_la_SOURCES += \
src/db/sysdb_ssh.c \
src/util/sss_ssh.c
endif
+if BUILD_SYSTEMTAP
+libsss_util_la_LIBADD += stap_generated_probes.lo
+endif
libsss_util_la_LDFLAGS = -avoid-version
pkglib_LTLIBRARIES += libsss_semanage.la
@@ -1064,6 +1070,39 @@ include_HEADERS += \
src/lib/sifp/sss_sifp_dbus.h
endif
+#########################
+# Systemtap tracing #
+#########################
+
+SYSTEMTAP_PROBES = \
+ $(srcdir)/src/systemtap/sssd_probes.d \
+ $(NULL)
+
+if BUILD_SYSTEMTAP
+stap_generated_probes.h: $(srcdir)/src/systemtap/sssd_probes.d
+ $(AM_V_GEN)$(DTRACE) -C -h -s $< -o $@
+
+stap_generated_probes.o: $(srcdir)/src/systemtap/sssd_probes.d
stap_generated_probes.h
+ $(AM_V_GEN)$(DTRACE) -C -G -s $< -o $@
+
+stap_generated_probes.lo: stap_generated_probes.o
+ $(AM_V_GEN)printf %s\\n \
+ '# $@ - a libtool object file' \
+ '# Generated by libtool (GNU libtool) 2.4' \
+ '# Actually generated by Makefile.am, in order to shut up libtool' \
+ "pic_object='$<'" \
+ "non_pic_object='$<'" \
+ > $@
+
+BUILT_SOURCES += stap_generated_probes.h
+
+CLEANFILES += stap_generated_probes.h \
+ stap_generated_probes.o \
+ stap_generated_probes.lo \
+ $(NULL)
+
+endif
+
####################
# Sbus Codegen #
####################
@@ -1096,7 +1135,7 @@ CODEGEN_CODE = \
$(CODEGEN_CODE): $(SBUS_CODEGEN)
-BUILT_SOURCES = $(CODEGEN_CODE)
+BUILT_SOURCES += $(CODEGEN_CODE)
####################
# Program Binaries #
@@ -3767,7 +3806,7 @@ endif
rm -f $(builddir)/src/sysv/systemd/sssd.service
rm -f $(builddir)/src/sysv/systemd/journal.conf
-CLEANFILES = *.X */*.X */*/*.X
+CLEANFILES += *.X */*.X */*/*.X
tests: all $(check_PROGRAMS)
(cd src/tests/cwrap && $(MAKE) $(AM_MAKEFLAGS) $@) || exit 1;
diff --git a/configure.ac b/configure.ac
index
b4ba366d7a32a45879e9f2e9b6e84256a3ac7235..2c208cd483db977c0b1f3902b1f3c35c649cd89c
100644
--- a/configure.ac
+++ b/configure.ac
@@ -183,6 +183,7 @@ m4_include([src/external/libnfsidmap.m4])
m4_include([src/external/cwrap.m4])
m4_include([src/external/libresolv.m4])
m4_include([src/external/intgcheck.m4])
+m4_include([src/external/systemtap.m4])
if test x$build_config_lib = xyes; then
m4_include([src/external/libaugeas.m4])
@@ -424,6 +425,9 @@ AM_CHECK_CMOCKA
AM_CHECK_UID_WRAPPER
AM_CHECK_NSS_WRAPPER
+# Check if the user wants SSSD to be compiled with systemtap probes
+AM_CHECK_SYSTEMTAP
+
SSS_ENABLE_INTGCHECK_REQS
AM_CONDITIONAL([HAVE_DEVSHM], [test -d /dev/shm])
diff --git a/src/external/systemtap.m4 b/src/external/systemtap.m4
new file mode 100644
index
0000000000000000000000000000000000000000..d1caa2017f0730394339f0a439046df6b56cb2ba
--- /dev/null
+++ b/src/external/systemtap.m4
@@ -0,0 +1,35 @@
+dnl A macro to check the availability of systemtap user-space probes
+AC_DEFUN([AM_CHECK_SYSTEMTAP],
+[
+ AC_ARG_ENABLE([systemtap],
+ [AS_HELP_STRING([--enable-systemtap],
+ [Enable inclusion of systemtap trace
support])],
+ [ENABLE_SYSTEMTAP="${enableval}"], [ENABLE_SYSTEMTAP='no'])
+
+ if test "x${ENABLE_SYSTEMTAP}" = xyes; then
+ AC_CHECK_PROGS(DTRACE, dtrace)
+ if test -z "$DTRACE"; then
+ AC_MSG_ERROR([dtrace not found])
+ fi
+
+ AC_CHECK_HEADER([sys/sdt.h], [SDT_H_FOUND='yes'],
+ [SDT_H_FOUND='no';
+ AC_MSG_ERROR([systemtap support needs sys/sdt.h
header])])
+
+ AC_DEFINE([HAVE_SYSTEMTAP], [1], [Define to 1 if systemtap is enabled])
+ HAVE_SYSTEMTAP=1
+
+ AC_ARG_WITH([tapset-install-dir],
+ [AS_HELP_STRING([--with-tapset-install-dir],
+ [The absolute path where the tapset dir
will be installed])],
+ [if test "x${withval}" = x; then
+ tapset_dir="\$(datadir)/systemtap/tapset"
+ else
+ tapset_dir="${withval}"
+ fi],
+ [tapset_dir="\$(datadir)/systemtap/tapset"])
+ AC_SUBST(tapset_dir)
+ fi
+
+ AM_CONDITIONAL([BUILD_SYSTEMTAP], [test x$HAVE_SYSTEMTAP = x1])
+])
diff --git a/src/systemtap/sssd_probes.d b/src/systemtap/sssd_probes.d
new file mode 100644
index
0000000000000000000000000000000000000000..7579577c8661e862d83b9fc7c9fe205d25be30ed
--- /dev/null
+++ b/src/systemtap/sssd_probes.d
@@ -0,0 +1,2 @@
+provider sssd {
+}
diff --git a/src/tests/cwrap/Makefile.am b/src/tests/cwrap/Makefile.am
index
ee9970667ab1ff8d5d84279113a773c183a4d739..0363c09f2667f352b2feb8281848e2afacdb000e
100644
--- a/src/tests/cwrap/Makefile.am
+++ b/src/tests/cwrap/Makefile.am
@@ -88,6 +88,9 @@ server_tests_LDADD = \
$(abs_top_builddir)/libsss_debug.la \
$(abs_top_builddir)/libsss_test_common.la \
$(NULL)
+if BUILD_SYSTEMTAP
+server_tests_LDADD += $(abs_top_builddir)/stap_generated_probes.lo
+endif
usertools_tests_SOURCES = \
test_usertools.c \
@@ -103,6 +106,9 @@ usertools_tests_LDADD = \
$(abs_top_builddir)/libsss_debug.la \
$(abs_top_builddir)/libsss_test_common.la \
$(NULL)
+if BUILD_SYSTEMTAP
+usertools_tests_LDADD += $(abs_top_builddir)/stap_generated_probes.lo
+endif
responder_common_tests_SOURCES =\
test_responder_common.c \
diff --git a/src/util/probes.h b/src/util/probes.h
index
349f29086e86a51b4551f09f542d0f45bf6f1aae..effce492d0a6cbcfe5b4c347b8931e102b853db2
100644
--- a/src/util/probes.h
+++ b/src/util/probes.h
@@ -20,6 +20,8 @@
#ifdef HAVE_SYSTEMTAP
+#include "stap_generated_probes.h"
+
/* Probe expansion inspired by libvirt */
#define PROBE_EXPAND(NAME, ...) NAME(__VA_ARGS__)
--
2.4.11
>From 59697d119f2bcf93b69dbb2afa6bead8b35ab752 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Mon, 29 Feb 2016 13:22:18 +0100
Subject: [PATCH 03/10] SYSDB: Track transaction nesting in sysdb_ctx
Adds an integer that tracks how deeply nested we are in sysdb
transactions. This will become useful later, because generally we are
only interested in level-0 transactions when probing, so we'll want to
pass the transaction nesting to the systemtap probes.
---
src/db/sysdb.c | 12 +++++++++---
src/db/sysdb_private.h | 1 +
2 files changed, 10 insertions(+), 3 deletions(-)
diff --git a/src/db/sysdb.c b/src/db/sysdb.c
index
d4366a3c76f114bf113567754a1e0417afe664e3..0c1dda7b888a80912eeee7bbbda4584a4bd6344e
100644
--- a/src/db/sysdb.c
+++ b/src/db/sysdb.c
@@ -895,7 +895,9 @@ int sysdb_transaction_start(struct sysdb_ctx *sysdb)
int ret;
ret = ldb_transaction_start(sysdb->ldb);
- if (ret != LDB_SUCCESS) {
+ if (ret == LDB_SUCCESS) {
+ sysdb->transaction_nesting++;
+ } else {
DEBUG(SSSDBG_CRIT_FAILURE,
"Failed to start ldb transaction! (%d)\n", ret);
}
@@ -907,7 +909,9 @@ int sysdb_transaction_commit(struct sysdb_ctx *sysdb)
int ret;
ret = ldb_transaction_commit(sysdb->ldb);
- if (ret != LDB_SUCCESS) {
+ if (ret == LDB_SUCCESS) {
+ sysdb->transaction_nesting--;
+ } else {
DEBUG(SSSDBG_CRIT_FAILURE,
"Failed to commit ldb transaction! (%d)\n", ret);
}
@@ -919,7 +923,9 @@ int sysdb_transaction_cancel(struct sysdb_ctx *sysdb)
int ret;
ret = ldb_transaction_cancel(sysdb->ldb);
- if (ret != LDB_SUCCESS) {
+ if (ret == LDB_SUCCESS) {
+ sysdb->transaction_nesting--;
+ } else {
DEBUG(SSSDBG_CRIT_FAILURE,
"Failed to cancel ldb transaction! (%d)\n", ret);
}
diff --git a/src/db/sysdb_private.h b/src/db/sysdb_private.h
index
c2c8d7a0585463806997c43bd020436edddd8517..b6c7fd162989aac3ae17da269fa4b1d967ca40f0
100644
--- a/src/db/sysdb_private.h
+++ b/src/db/sysdb_private.h
@@ -89,6 +89,7 @@
struct sysdb_ctx {
struct ldb_context *ldb;
char *ldb_file;
+ int transaction_nesting;
};
/* Internal utility functions */
--
2.4.11
>From e91568d6ebcdfe7777024f7b6fe752d1d6a40b13 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Mon, 29 Feb 2016 13:20:28 +0100
Subject: [PATCH 04/10] SYSDB: Add systemtap probes to track sysdb transactions
Actually adds marks for sysdb transactions that receive the transaction
nesting level as an argument. The nesting is passed on from probes to
marks along with a human-friendly description.
The transaction commit is decorated with two probes, before and after.
This would allow the caller to distinguish between the time we spend in
the transaction (which might be important, because if a transaction is
active on an ldb context, even the readers are blocked before the
transaction completes) and the time we spend commiting the transaction
(which is important because that's when the disk writes occur)
The probes would be installed into /usr/share/systemtap/tapset on RHEL
and Fedora. This is in line with systemtap's paths which are described
in detail in "man 7 stappaths".
---
Makefile.am | 4 +++-
configure.ac | 1 +
src/db/sysdb.c | 5 +++++
src/systemtap/sssd.stp.in | 32 ++++++++++++++++++++++++++++++++
src/systemtap/sssd_probes.d | 4 ++++
5 files changed, 45 insertions(+), 1 deletion(-)
create mode 100644 src/systemtap/sssd.stp.in
diff --git a/Makefile.am b/Makefile.am
index
0cdfd54e7e7bc685e712b2ff01cc5c551f1c05cf..87f0741c3dac0de57542c365daa5eb95d5e3fe2f
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -79,6 +79,7 @@ pkgconfigdir = $(libdir)/pkgconfig
krb5rcachedir = @krb5rcachedir@
sudolibdir = @sudolibpath@
polkitdir = @polkitdir@
+systemtap_tapdir = @tapset_dir@
UNICODE_LIBS=@UNICODE_LIBS@
@@ -1078,6 +1079,8 @@ SYSTEMTAP_PROBES = \
$(srcdir)/src/systemtap/sssd_probes.d \
$(NULL)
+dist_systemtap_tap_DATA = $(builddir)/src/systemtap/sssd.stp
+
if BUILD_SYSTEMTAP
stap_generated_probes.h: $(srcdir)/src/systemtap/sssd_probes.d
$(AM_V_GEN)$(DTRACE) -C -h -s $< -o $@
@@ -1100,7 +1103,6 @@ CLEANFILES += stap_generated_probes.h \
stap_generated_probes.o \
stap_generated_probes.lo \
$(NULL)
-
endif
####################
diff --git a/configure.ac b/configure.ac
index
2c208cd483db977c0b1f3902b1f3c35c649cd89c..f91150e018850f4ee7753c4d257febc29531012b
100644
--- a/configure.ac
+++ b/configure.ac
@@ -457,5 +457,6 @@ AC_CONFIG_FILES([Makefile contrib/sssd.spec
src/examples/rwtab src/doxy.config
src/lib/sifp/sss_simpleifp.doxy
src/config/setup.py
src/responder/ifp/org.freedesktop.sssd.infopipe.service
+ src/systemtap/sssd.stp
src/config/SSSDConfig/__init__.py])
AC_OUTPUT
diff --git a/src/db/sysdb.c b/src/db/sysdb.c
index
0c1dda7b888a80912eeee7bbbda4584a4bd6344e..56a1901677a9ef2585582b6643df06031aef0bba
100644
--- a/src/db/sysdb.c
+++ b/src/db/sysdb.c
@@ -25,6 +25,7 @@
#include "util/sss_utf8.h"
#include "db/sysdb_private.h"
#include "confdb/confdb.h"
+#include "util/probes.h"
#include <time.h>
#define LDB_MODULES_PATH "LDB_MODULES_PATH"
@@ -896,6 +897,7 @@ int sysdb_transaction_start(struct sysdb_ctx *sysdb)
ret = ldb_transaction_start(sysdb->ldb);
if (ret == LDB_SUCCESS) {
+ PROBE(SYSDB_TRANSACTION_START, sysdb->transaction_nesting);
sysdb->transaction_nesting++;
} else {
DEBUG(SSSDBG_CRIT_FAILURE,
@@ -908,9 +910,11 @@ int sysdb_transaction_commit(struct sysdb_ctx *sysdb)
{
int ret;
+ PROBE(SYSDB_TRANSACTION_COMMIT_BEFORE, sysdb->transaction_nesting-1);
ret = ldb_transaction_commit(sysdb->ldb);
if (ret == LDB_SUCCESS) {
sysdb->transaction_nesting--;
+ PROBE(SYSDB_TRANSACTION_COMMIT_AFTER, sysdb->transaction_nesting);
} else {
DEBUG(SSSDBG_CRIT_FAILURE,
"Failed to commit ldb transaction! (%d)\n", ret);
@@ -925,6 +929,7 @@ int sysdb_transaction_cancel(struct sysdb_ctx *sysdb)
ret = ldb_transaction_cancel(sysdb->ldb);
if (ret == LDB_SUCCESS) {
sysdb->transaction_nesting--;
+ PROBE(SYSDB_TRANSACTION_CANCEL, sysdb->transaction_nesting);
} else {
DEBUG(SSSDBG_CRIT_FAILURE,
"Failed to cancel ldb transaction! (%d)\n", ret);
diff --git a/src/systemtap/sssd.stp.in b/src/systemtap/sssd.stp.in
new file mode 100644
index
0000000000000000000000000000000000000000..2bd45aeb88f2a2052221ef4890aaa580330334ec
--- /dev/null
+++ b/src/systemtap/sssd.stp.in
@@ -0,0 +1,32 @@
+# Database transaction probes
+probe sssd_transaction_start =
process("@libdir@/sssd/libsss_util.so").mark("sysdb_transaction_start")
+{
+ nesting = $arg1;
+ probestr = sprintf("-> %s(nesting=%d)",
+ $$name,
+ nesting);
+}
+
+probe sssd_transaction_commit_before =
process("@libdir@/sssd/libsss_util.so").mark("sysdb_transaction_commit_before")
+{
+ nesting = $arg1;
+ probestr = sprintf("<- %s(pre)(nesting=%d)",
+ $$name,
+ nesting);
+}
+
+probe sssd_transaction_commit_after =
process("@libdir@/sssd/libsss_util.so").mark("sysdb_transaction_commit_after")
+{
+ nesting = $arg1;
+ probestr = sprintf("<- %s(post)(nesting=%d)",
+ $$name,
+ nesting);
+}
+
+probe sssd_transaction_cancel =
process("@libdir@/sssd/libsss_util.so").mark("sysdb_transaction_cancel")
+{
+ nesting = $arg1;
+ probestr = sprintf("<- %s(nesting=%d)",
+ $$name,
+ nesting);
+}
diff --git a/src/systemtap/sssd_probes.d b/src/systemtap/sssd_probes.d
index
7579577c8661e862d83b9fc7c9fe205d25be30ed..f4890ddfdd82e67a30a955634b57b97fcaea4491
100644
--- a/src/systemtap/sssd_probes.d
+++ b/src/systemtap/sssd_probes.d
@@ -1,2 +1,6 @@
provider sssd {
+ probe sysdb_transaction_start(int nesting);
+ probe sysdb_transaction_commit_before(int nesting);
+ probe sysdb_transaction_commit_after(int nesting);
+ probe sysdb_transaction_cancel(int nesting);
}
--
2.4.11
>From 3573351539870f4dc366731664a6e04361ae5199 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Tue, 3 May 2016 12:34:29 +0200
Subject: [PATCH 05/10] STAP: Add helper functions to for human-readable
account request representation
The caller of the systemtap script would be able to see what kind of
account request sssd received with a string representation, not just the
cryptic hexadecimal number.
---
Makefile.am | 5 ++-
src/providers/data_provider_req.h | 2 ++
src/systemtap/sssd_functions.stp | 66 +++++++++++++++++++++++++++++++++++++++
3 files changed, 72 insertions(+), 1 deletion(-)
create mode 100644 src/systemtap/sssd_functions.stp
diff --git a/Makefile.am b/Makefile.am
index
87f0741c3dac0de57542c365daa5eb95d5e3fe2f..b87db91ee22300da670ff8e57eedea3355a5ed11
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1079,7 +1079,10 @@ SYSTEMTAP_PROBES = \
$(srcdir)/src/systemtap/sssd_probes.d \
$(NULL)
-dist_systemtap_tap_DATA = $(builddir)/src/systemtap/sssd.stp
+dist_systemtap_tap_DATA = \
+ $(builddir)/src/systemtap/sssd.stp \
+ $(builddir)/src/systemtap/sssd_functions.stp \
+ $(NULL)
if BUILD_SYSTEMTAP
stap_generated_probes.h: $(srcdir)/src/systemtap/sssd_probes.d
diff --git a/src/providers/data_provider_req.h
b/src/providers/data_provider_req.h
index
338f8192f80f732b89c5dc3dd3b79fb5a6edb8c7..a2889cda5c27d91ac42eaeb3777e5ec9181f31f9
100644
--- a/src/providers/data_provider_req.h
+++ b/src/providers/data_provider_req.h
@@ -24,6 +24,8 @@
#include <dbus/dbus.h>
+/* When changing these constants, also please change sssd_functions.stp
+ */
#define BE_REQ_USER 0x0001
#define BE_REQ_GROUP 0x0002
#define BE_REQ_INITGROUPS 0x0003
diff --git a/src/systemtap/sssd_functions.stp b/src/systemtap/sssd_functions.stp
new file mode 100644
index
0000000000000000000000000000000000000000..bad194eadb1b7154e85bb05c42240323896abe45
--- /dev/null
+++ b/src/systemtap/sssd_functions.stp
@@ -0,0 +1,66 @@
+function acct_req_desc(entry_type)
+{
+ if (entry_type == 0x0001) {
+ str_entry_type = "user"
+ } else if (entry_type == 0x0002) {
+ str_entry_type = "group"
+ } else if (entry_type == 0x0003) {
+ str_entry_type = "initgroups"
+ } else if (entry_type == 0x0004) {
+ str_entry_type = "netgroups"
+ } else if (entry_type == 0x0005) {
+ str_entry_type = "services"
+ } else if (entry_type == 0x0006) {
+ str_entry_type = "sudo_full"
+ } else if (entry_type == 0x0007) {
+ str_entry_type = "sudo_rules"
+ # See src/providers/data_provider_req.h, no 0x0008 there..
+ } else if (entry_type == 0x0009) {
+ str_entry_type = "autofs"
+ } else if (entry_type == 0x0010) {
+ str_entry_type = "host"
+ } else if (entry_type == 0x0011) {
+ str_entry_type = "by_secid"
+ } else if (entry_type == 0x0012) {
+ str_entry_type = "user_and_group"
+ } else if (entry_type == 0x0013) {
+ str_entry_type = "by_uuid"
+ } else if (entry_type == 0x0014) {
+ str_entry_type = "by_cert"
+ } else {
+ str_entry_type = sprintf("%X", entry_type)
+ }
+
+ return str_entry_type
+}
+
+function sssd_acct_req_probestr(fc_name, entry_type, filter_type,
+ filter_value, extra_value)
+{
+ str_entry_type = acct_req_desc(entry_type)
+
+ # Maybe we could use guru mode here and include the constants
+ # directly..
+ if (filter_type == 1) {
+ str_filter_type = "name"
+ } else if (filter_type == 2) {
+ str_filter_type = "idnum"
+ } else if (filter_type == 3) {
+ str_filter_type = "enum"
+ } else if (filter_type == 4) {
+ str_filter_type = "secid"
+ } else if (filter_type == 5) {
+ str_filter_type = "uuid"
+ } else if (filter_type == 6) {
+ str_filter_type = "cert"
+ } else if (filter_type == 7) {
+ str_filter_type = "wildcard"
+ } else {
+ str_filter_type = sprintf("%d", filter_type)
+ }
+
+ probestr = sprintf("%s(entry_type=%s, filter_type=%s, filter_value=%s,
extra_value=%s)",
+ fc_name, str_entry_type, str_filter_type,
+ filter_value, extra_value)
+ return probestr
+}
--
2.4.11
>From d9bf5122bdcb8cf51356934dd2d7b63b3282dee2 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Tue, 1 Dec 2015 23:25:05 +0100
Subject: [PATCH 06/10] LDAP: Decorate the hot paths in the LDAP provider with
systemtap probes
During performance analysis, the LDAP provider and especially its nested
group code proved to be the place where we spend the most time during
account requests. Therefore, I decorated the LDAP provider with
systemtap probes to be able to observe where the time is spent.
The code allows passing of search properties (base, filter, ...) from
marks to probes. Where applicable, the probes pass on these arguments to
functions and build a human-readable string representation.
---
Makefile.am | 6 +
src/providers/ldap/ldap_id.c | 11 ++
src/providers/ldap/sdap_async.c | 17 ++
src/providers/ldap/sdap_async_groups.c | 7 +
src/providers/ldap/sdap_async_nested_groups.c | 38 +++++
src/providers/ldap/sdap_async_users.c | 8 +
src/systemtap/sssd.stp.in | 224 ++++++++++++++++++++++++++
src/systemtap/sssd_probes.d | 62 +++++++
8 files changed, 373 insertions(+)
diff --git a/Makefile.am b/Makefile.am
index
b87db91ee22300da670ff8e57eedea3355a5ed11..e0b01190cde7933fdd9cbfb617a201da85f367ab
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -2165,6 +2165,9 @@ nestedgroups_tests_LDADD = \
libsss_idmap.la \
libsss_test_common.la \
$(NULL)
+if BUILD_SYSTEMTAP
+nestedgroups_tests_LDADD += stap_generated_probes.lo
+endif
test_sss_idmap_SOURCES = \
src/tests/cmocka/test_sss_idmap.c
@@ -2984,6 +2987,9 @@ libsss_ldap_common_la_LIBADD = \
libsss_ldap_common_la_LDFLAGS = \
-avoid-version \
$(NULL)
+if BUILD_SYSTEMTAP
+libsss_ldap_common_la_LIBADD += stap_generated_probes.lo
+endif
if BUILD_SUDO
libsss_ldap_common_la_SOURCES += \
diff --git a/src/providers/ldap/ldap_id.c b/src/providers/ldap/ldap_id.c
index
8923e7e0c3fdae4614d6bfef2665de7854b62e8e..ee5b374db2af69325d03a6fe0fcf33990fe9afa0
100644
--- a/src/providers/ldap/ldap_id.c
+++ b/src/providers/ldap/ldap_id.c
@@ -27,6 +27,7 @@
#include <sys/time.h>
#include "util/util.h"
+#include "util/probes.h"
#include "util/strtonum.h"
#include "util/cert.h"
#include "db/sysdb.h"
@@ -1509,6 +1510,11 @@ sdap_handle_acct_req_send(TALLOC_CTX *mem_ctx,
goto done;
}
+ PROBE(SDAP_ACCT_REQ_SEND,
+ state->ar->entry_type & BE_REQ_TYPE_MASK,
+ state->ar->filter_type, state->ar->filter_value,
+ PROBE_SAFE_STR(state->ar->extra_value));
+
switch (ar->entry_type & BE_REQ_TYPE_MASK) {
case BE_REQ_USER: /* user */
subreq = users_get_send(state, be_ctx->ev, id_ctx,
@@ -1730,6 +1736,11 @@ sdap_handle_acct_req_recv(struct tevent_req *req,
state = tevent_req_data(req, struct sdap_handle_acct_req_state);
+ PROBE(SDAP_ACCT_REQ_RECV,
+ state->ar->entry_type & BE_REQ_TYPE_MASK,
+ state->ar->filter_type, state->ar->filter_value,
+ PROBE_SAFE_STR(state->ar->extra_value));
+
if (_dp_error) {
*_dp_error = state->dp_error;
}
diff --git a/src/providers/ldap/sdap_async.c b/src/providers/ldap/sdap_async.c
index
d15a2215a6191ed5fd6cd01a030b31bd098ea074..0c67e54c8a981442b7983a3f68db1bde3a2a6280
100644
--- a/src/providers/ldap/sdap_async.c
+++ b/src/providers/ldap/sdap_async.c
@@ -23,6 +23,7 @@
#include <ctype.h>
#include "util/util.h"
#include "util/strtonum.h"
+#include "util/probes.h"
#include "providers/ldap/sdap_async_private.h"
#define REPLY_REALLOC_INCREMENT 10
@@ -1295,6 +1296,9 @@ sdap_get_generic_ext_send(TALLOC_CTX *memctx,
}
state->serverctrls[i] = NULL;
+ PROBE(SDAP_GET_GENERIC_EXT_SEND, state->search_base,
+ state->scope, state->filter);
+
ret = sdap_get_generic_ext_step(req);
if (ret != EOK) {
tevent_req_error(req, ret);
@@ -1632,6 +1636,9 @@ sdap_get_generic_ext_recv(struct tevent_req *req,
struct sdap_get_generic_ext_state *state =
tevent_req_data(req, struct sdap_get_generic_ext_state);
+ PROBE(SDAP_GET_GENERIC_EXT_RECV, state->search_base,
+ state->scope, state->filter);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
if (ref_count) {
@@ -2773,6 +2780,9 @@ enum sdap_deref_type {
struct sdap_deref_search_state {
struct sdap_handle *sh;
+ const char *base_dn;
+ const char *deref_attr;
+
size_t reply_count;
struct sdap_deref_attrs **reply;
enum sdap_deref_type deref_type;
@@ -2868,6 +2878,10 @@ sdap_deref_search_send(TALLOC_CTX *memctx,
state->sh = sh;
state->reply_count = 0;
state->reply = NULL;
+ state->base_dn = base_dn;
+ state->deref_attr = deref_attr;
+
+ PROBE(SDAP_DEREF_SEARCH_SEND, state->base_dn, state->deref_attr);
if (sdap_is_control_supported(sh, LDAP_SERVER_ASQ_OID)) {
DEBUG(SSSDBG_TRACE_INTERNAL, "Server supports ASQ\n");
@@ -2962,6 +2976,9 @@ int sdap_deref_search_recv(struct tevent_req *req,
{
struct sdap_deref_search_state *state = tevent_req_data(req,
struct sdap_deref_search_state);
+
+ PROBE(SDAP_DEREF_SEARCH_RECV, state->base_dn, state->deref_attr);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
*reply_count = state->reply_count;
diff --git a/src/providers/ldap/sdap_async_groups.c
b/src/providers/ldap/sdap_async_groups.c
index
f4633a69c7dcd2bf29778408d9e3b88bef99f6ab..86f0a7d6ef0e97568d8a0b5e14f6b65fcee6d8cb
100644
--- a/src/providers/ldap/sdap_async_groups.c
+++ b/src/providers/ldap/sdap_async_groups.c
@@ -22,6 +22,7 @@
*/
#include "util/util.h"
+#include "util/probes.h"
#include "db/sysdb.h"
#include "providers/ldap/sdap_async_private.h"
#include "providers/ldap/ldap_common.h"
@@ -2371,16 +2372,20 @@ static void sdap_nested_done(struct tevent_req *subreq)
}
in_transaction = true;
+ PROBE(SDAP_NESTED_GROUP_POPULATE_PRE);
ret = sdap_nested_group_populate_users(state, state->sysdb,
state->dom, state->opts,
users, user_count, &ghosts);
+ PROBE(SDAP_NESTED_GROUP_POPULATE_POST);
if (ret != EOK) {
goto fail;
}
+ PROBE(SDAP_NESTED_GROUP_SAVE_PRE);
ret = sdap_save_groups(state, state->sysdb, state->dom, state->opts,
groups, group_count, false, ghosts, true,
&state->higher_usn);
+ PROBE(SDAP_NESTED_GROUP_SAVE_POST);
if (ret != EOK) {
goto fail;
}
@@ -2539,8 +2544,10 @@ static errno_t
sdap_nested_group_populate_users(TALLOC_CTX *mem_ctx,
ret = ENOMEM;
goto done;
}
+ PROBE(SDAP_NESTED_GROUP_POPULATE_SEARCH_USERS_PRE);
ret = sysdb_search_users(tmp_ctx, user_dom, filter,
search_attrs, &count, &msgs);
+ PROBE(SDAP_NESTED_GROUP_POPULATE_SEARCH_USERS_POST);
talloc_zfree(filter);
talloc_zfree(clean_orig_dn);
if (ret != EOK && ret != ENOENT) {
diff --git a/src/providers/ldap/sdap_async_nested_groups.c
b/src/providers/ldap/sdap_async_nested_groups.c
index
a1690d7bd9ca5e1c19b5edf4c99bfee40d1f3e16..1ebf66067d9412b8f4bb7fd1f7aa0326f43cd9c2
100644
--- a/src/providers/ldap/sdap_async_nested_groups.c
+++ b/src/providers/ldap/sdap_async_nested_groups.c
@@ -30,6 +30,7 @@
#include <time.h>
#include "util/util.h"
+#include "util/probes.h"
#include "db/sysdb.h"
#include "providers/ldap/ldap_common.h"
#include "providers/ldap/sdap_async.h"
@@ -479,7 +480,9 @@ sdap_nested_group_check_cache(struct sdap_options *opts,
member_domain = sdap_domain == NULL ? domain : sdap_domain->dom;
/* search in users */
+ PROBE(SDAP_NESTED_GROUP_SYSDB_SEARCH_USERS_PRE);
ret = sdap_nested_group_sysdb_search_users(member_domain, filter);
+ PROBE(SDAP_NESTED_GROUP_SYSDB_SEARCH_USERS_POST);
if (ret == EOK || ret == EAGAIN) {
/* user found */
*_type = SDAP_NESTED_GROUP_DN_USER;
@@ -490,7 +493,9 @@ sdap_nested_group_check_cache(struct sdap_options *opts,
}
/* search in groups */
+ PROBE(SDAP_NESTED_GROUP_SYSDB_SEARCH_GROUPS_PRE);
ret = sdap_nested_group_sysdb_search_groups(member_domain, filter);
+ PROBE(SDAP_NESTED_GROUP_SYSDB_SEARCH_GROUPS_POST);
if (ret == EOK || ret == EAGAIN) {
/* group found */
*_type = SDAP_NESTED_GROUP_DN_GROUP;
@@ -620,8 +625,10 @@ sdap_nested_group_split_members(TALLOC_CTX *mem_ctx,
}
/* check sysdb */
+ PROBE(SDAP_NESTED_GROUP_CHECK_CACHE_PRE);
ret = sdap_nested_group_check_cache(group_ctx->opts, group_ctx->domain,
dn, &type);
+ PROBE(SDAP_NESTED_GROUP_CHECK_CACHE_POST);
if (ret == EOK) {
/* found and valid */
DEBUG(SSSDBG_TRACE_ALL, "[%s] found in cache, skipping\n", dn);
@@ -795,6 +802,8 @@ sdap_nested_group_send(TALLOC_CTX *mem_ctx,
errno_t ret;
int i;
+ PROBE(SDAP_NESTED_GROUP_SEND);
+
req = tevent_req_create(mem_ctx, &state, struct sdap_nested_group_state);
if (req == NULL) {
DEBUG(SSSDBG_CRIT_FAILURE, "tevent_req_create() failed\n");
@@ -935,6 +944,7 @@ errno_t sdap_nested_group_recv(TALLOC_CTX *mem_ctx,
state = tevent_req_data(req, struct sdap_nested_group_state);
+ PROBE(SDAP_NESTED_GROUP_RECV);
TEVENT_REQ_RETURN_ON_ERROR(req);
ret = sdap_nested_group_extract_hash_table(state, state->group_ctx->users,
@@ -1035,6 +1045,7 @@ sdap_nested_group_process_send(TALLOC_CTX *mem_ctx,
}
DEBUG(SSSDBG_TRACE_INTERNAL, "About to process group [%s]\n", orig_dn);
+ PROBE(SDAP_NESTED_GROUP_PROCESS_SEND, state->group_dn);
/* get member list, both direct and external */
state->ext_members = sdap_nested_group_ext_members(state->group_ctx->opts,
@@ -1052,11 +1063,13 @@ sdap_nested_group_process_send(TALLOC_CTX *mem_ctx,
}
/* get members that need to be refreshed */
+ PROBE(SDAP_NESTED_GROUP_PROCESS_SPLIT_PRE);
ret = sdap_nested_group_split_members(state, state->group_ctx,
state->nesting_level, members,
&state->missing,
&state->num_missing_total,
&state->num_missing_groups);
+ PROBE(SDAP_NESTED_GROUP_PROCESS_SPLIT_POST);
if (ret != EOK) {
DEBUG(SSSDBG_CRIT_FAILURE, "Unable to split member list "
"[%d]: %s\n", ret, sss_strerror(ret));
@@ -1178,6 +1191,13 @@ done:
static errno_t sdap_nested_group_process_recv(struct tevent_req *req)
{
+#ifdef HAVE_SYSTEMTAP
+ struct sdap_nested_group_process_state *state = NULL;
+ state = tevent_req_data(req, struct sdap_nested_group_process_state);
+
+ PROBE(SDAP_NESTED_GROUP_PROCESS_RECV, state->group_dn);
+#endif
+
TEVENT_REQ_RETURN_ON_ERROR(req);
return EOK;
@@ -1683,6 +1703,8 @@ sdap_nested_group_lookup_user_send(TALLOC_CTX *mem_ctx,
return NULL;
}
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_USER_SEND);
+
if (group_ctx->opts->schema_type == SDAP_SCHEMA_IPA_V1) {
/* if the schema is IPA, then just shortcut and guess the name */
ret = sdap_nested_group_get_ipa_user(state, member->dn,
@@ -1799,6 +1821,8 @@ static errno_t
sdap_nested_group_lookup_user_recv(TALLOC_CTX *mem_ctx,
struct sdap_nested_group_lookup_user_state *state = NULL;
state = tevent_req_data(req, struct sdap_nested_group_lookup_user_state);
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_USER_RECV);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
if (_user != NULL) {
@@ -1830,6 +1854,8 @@ sdap_nested_group_lookup_group_send(TALLOC_CTX *mem_ctx,
char *oc_list;
errno_t ret;
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_GROUP_SEND);
+
req = tevent_req_create(mem_ctx, &state,
struct sdap_nested_group_lookup_group_state);
if (req == NULL) {
@@ -1941,6 +1967,8 @@ static errno_t
sdap_nested_group_lookup_group_recv(TALLOC_CTX *mem_ctx,
struct sdap_nested_group_lookup_group_state *state = NULL;
state = tevent_req_data(req, struct sdap_nested_group_lookup_group_state);
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_GROUP_RECV);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
if (_group != NULL) {
@@ -1982,6 +2010,8 @@ sdap_nested_group_lookup_unknown_send(TALLOC_CTX *mem_ctx,
return NULL;
}
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_UNKNOWN_SEND);
+
state->ev = ev;
state->group_ctx = group_ctx;
state->member = member;
@@ -2109,6 +2139,8 @@ sdap_nested_group_lookup_unknown_recv(TALLOC_CTX *mem_ctx,
struct sdap_nested_group_lookup_unknown_state *state = NULL;
state = tevent_req_data(req, struct
sdap_nested_group_lookup_unknown_state);
+ PROBE(SDAP_NESTED_GROUP_LOOKUP_UNKNOWN_RECV);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
if (_entry != NULL) {
@@ -2161,6 +2193,8 @@ sdap_nested_group_deref_send(TALLOC_CTX *mem_ctx,
return NULL;
}
+ PROBE(SDAP_NESTED_GROUP_DEREF_SEND);
+
state->ev = ev;
state->group_ctx = group_ctx;
state->members = members;
@@ -2262,6 +2296,7 @@ sdap_nested_group_deref_direct_process(struct tevent_req
*subreq)
goto done;
}
+ PROBE(SDAP_NESTED_GROUP_DEREF_PROCESS_PRE);
for (i = 0; i < num_entries; i++) {
ret = sysdb_attrs_get_string(entries[i]->attrs,
SYSDB_ORIG_DN, &orig_dn);
@@ -2364,6 +2399,7 @@ sdap_nested_group_deref_direct_process(struct tevent_req
*subreq)
continue;
}
}
+ PROBE(SDAP_NESTED_GROUP_DEREF_PROCESS_POST);
/* adjust size of nested groups array */
if (state->num_groups > 0) {
@@ -2453,6 +2489,8 @@ static void sdap_nested_group_deref_done(struct
tevent_req *subreq)
static errno_t sdap_nested_group_deref_recv(struct tevent_req *req)
{
+ PROBE(SDAP_NESTED_GROUP_DEREF_RECV);
+
TEVENT_REQ_RETURN_ON_ERROR(req);
return EOK;
diff --git a/src/providers/ldap/sdap_async_users.c
b/src/providers/ldap/sdap_async_users.c
index
480bbc2031249a66abf61737f6c86a7afdd3885f..c74d2aa8a7022d17f4832cd2904c7e5cd766d5d0
100644
--- a/src/providers/ldap/sdap_async_users.c
+++ b/src/providers/ldap/sdap_async_users.c
@@ -22,6 +22,7 @@
*/
#include "util/util.h"
+#include "util/probes.h"
#include "db/sysdb.h"
#include "providers/ldap/sdap_async_private.h"
#include "providers/ldap/ldap_common.h"
@@ -840,6 +841,7 @@ struct sdap_get_users_state {
struct sysdb_ctx *sysdb;
struct sdap_options *opts;
struct sss_domain_info *dom;
+ const char *filter;
char *higher_usn;
struct sysdb_attrs **users;
@@ -872,6 +874,9 @@ struct tevent_req *sdap_get_users_send(TALLOC_CTX *memctx,
state->opts = opts;
state->dom = dom;
+ state->filter = filter;
+ PROBE(SDAP_SEARCH_USER_SEND, state->filter);
+
subreq = sdap_search_user_send(state, ev, dom, opts, search_bases,
sh, attrs, filter, timeout, lookup_type);
if (subreq == NULL) {
@@ -907,10 +912,12 @@ static void sdap_get_users_done(struct tevent_req *subreq)
return;
}
+ PROBE(SDAP_SEARCH_USER_SAVE_BEGIN, state->filter);
ret = sdap_save_users(state, state->sysdb,
state->dom, state->opts,
state->users, state->count,
&state->higher_usn);
+ PROBE(SDAP_SEARCH_USER_SAVE_END, state->filter);
if (ret) {
DEBUG(SSSDBG_OP_FAILURE, "Failed to store users [%d][%s].\n",
ret, sss_strerror(ret));
@@ -929,6 +936,7 @@ int sdap_get_users_recv(struct tevent_req *req,
struct sdap_get_users_state *state = tevent_req_data(req,
struct sdap_get_users_state);
+ PROBE(SDAP_SEARCH_USER_RECV, state->filter);
TEVENT_REQ_RETURN_ON_ERROR(req);
if (usn_value) {
diff --git a/src/systemtap/sssd.stp.in b/src/systemtap/sssd.stp.in
index
2bd45aeb88f2a2052221ef4890aaa580330334ec..199916383105c34e60f3cb9b06d04d6c483b9712
100644
--- a/src/systemtap/sssd.stp.in
+++ b/src/systemtap/sssd.stp.in
@@ -30,3 +30,227 @@ probe sssd_transaction_cancel =
process("@libdir@/sssd/libsss_util.so").mark("sy
$$name,
nesting);
}
+
+# LDAP search probes
+probe sdap_search_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_get_generic_ext_send")
+{
+ base = user_string($arg1);
+ scope = $arg2;
+ filter = user_string($arg3);
+
+ probestr = sprintf("-> search base [%s] scope [%d] filter [%s]",
+ base, scope, filter);
+}
+
+probe sdap_search_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_get_generic_ext_recv")
+{
+ base = user_string($arg1);
+ scope = $arg2;
+ filter = user_string($arg3);
+
+ probestr = sprintf("<- search base [%s] scope [%d] filter [%s]",
+ base, scope, filter);
+}
+
+probe sdap_deref_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_deref_search_send")
+{
+ base_dn = user_string($arg1);
+ deref_attr = user_string($arg2);
+
+ probestr = sprintf("-> (%s)(base_dn=[%s],deref_attr=[%s])",
+ $$name, base_dn, deref_attr);
+}
+
+probe sdap_deref_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_deref_search_recv")
+{
+ base_dn = user_string($arg1);
+ deref_attr = user_string($arg2);
+
+ probestr = sprintf("-> (%s)(base_dn=[%s],deref_attr=[%s])",
+ $$name, base_dn, deref_attr);
+}
+
+# LDAP account request probes
+probe sdap_acct_req_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_acct_req_send")
+{
+ entry_type = $arg1;
+ filter_type = $arg2;
+ filter_value = user_string($arg3);
+ extra_value = user_string($arg4);
+}
+
+probe sdap_acct_req_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_acct_req_recv")
+{
+ entry_type = $arg1;
+ filter_type = $arg2;
+ filter_value = user_string($arg3);
+ extra_value = user_string($arg4);
+}
+
+# LDAP user search probes
+probe sdap_search_user_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_search_user_send")
+{
+ filter = user_string($arg1);
+}
+
+probe sdap_search_user_save_begin =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_search_user_save_begin")
+{
+ filter = user_string($arg1);
+}
+
+probe sdap_search_user_save_end =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_search_user_save_end")
+{
+ filter = user_string($arg1);
+}
+
+probe sdap_search_user_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_search_user_recv")
+{
+ filter = user_string($arg1);
+}
+
+# LDAP group search probes
+probe sdap_nested_group_populate_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_populate_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_populate_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_populate_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_save_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_save_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_save_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_save_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_user_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_user_send")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_user_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_user_recv")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_group_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_group_send")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_group_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_group_recv")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_unknown_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_unknown_send")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_lookup_unknown_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_lookup_unknown_recv")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_deref_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_deref_send")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_deref_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_deref_recv")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_deref_process_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_deref_process_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_deref_process_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_deref_process_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_send")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_recv")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_process_send =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_process_send")
+{
+ orig_dn = user_string($arg1);
+
+ probestr = sprintf("-> %s(orig_dn=[%s])",
+ $$name, orig_dn);
+}
+
+probe sdap_nested_group_process_split_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_process_split_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_process_split_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_process_split_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_check_cache_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_check_cache_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_check_cache_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_check_cache_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_sysdb_search_users_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_sysdb_search_users_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_sysdb_search_users_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_sysdb_search_users_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_sysdb_search_groups_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_sysdb_search_groups_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_sysdb_search_groups_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_sysdb_search_groups_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_populate_search_users_pre =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_populate_search_users_pre")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_populate_search_users_post =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_populate_search_users_post")
+{
+ # No arguments
+}
+
+probe sdap_nested_group_process_recv =
process("@libdir@/sssd/libsss_ldap_common.so").mark("sdap_nested_group_process_recv")
+{
+ orig_dn = user_string($arg1);
+
+ probestr = sprintf("-> %s(orig_dn=[%s])",
+ $$name, orig_dn);
+}
diff --git a/src/systemtap/sssd_probes.d b/src/systemtap/sssd_probes.d
index
f4890ddfdd82e67a30a955634b57b97fcaea4491..33339b415cd084d2a9348a5cd5f46065c0504233
100644
--- a/src/systemtap/sssd_probes.d
+++ b/src/systemtap/sssd_probes.d
@@ -3,4 +3,66 @@ provider sssd {
probe sysdb_transaction_commit_before(int nesting);
probe sysdb_transaction_commit_after(int nesting);
probe sysdb_transaction_cancel(int nesting);
+
+ probe sdap_acct_req_send(int entry_type,
+ int filter_type,
+ char *filter_value,
+ char *extra_value);
+ probe sdap_acct_req_recv(int entry_type,
+ int filter_type,
+ char *filter_value,
+ char *extra_value);
+
+ probe sdap_search_user_send(const char *filter);
+ probe sdap_search_user_save_begin(const char *filter);
+ probe sdap_search_user_save_end(const char *filter);
+ probe sdap_search_user_recv(const char *filter);
+
+ probe sdap_get_generic_ext_send(const char *base, int scope, const char
*filter);
+ probe sdap_get_generic_ext_recv(const char *base, int scope, const char
*filter);
+
+ probe sdap_deref_search_send(const char *base_dn, const char *deref_attr);
+ probe sdap_deref_search_recv(const char *base_dn, const char *deref_attr);
+
+ probe sdap_nested_group_populate_pre();
+ probe sdap_nested_group_populate_post();
+
+ probe sdap_nested_group_save_pre();
+ probe sdap_nested_group_save_post();
+
+ probe sdap_nested_group_lookup_user_send();
+ probe sdap_nested_group_lookup_user_recv();
+
+ probe sdap_nested_group_lookup_group_send();
+ probe sdap_nested_group_lookup_group_recv();
+
+ probe sdap_nested_group_lookup_unknown_send();
+ probe sdap_nested_group_lookup_unknown_recv();
+
+ probe sdap_nested_group_deref_send();
+ probe sdap_nested_group_deref_process_pre();
+ probe sdap_nested_group_deref_process_post();
+ probe sdap_nested_group_deref_recv();
+
+ probe sdap_save_group_pre();
+ probe sdap_save_group_post();
+
+ probe sdap_save_grpmem_pre();
+ probe sdap_save_grpmem_post();
+
+ probe sdap_nested_group_send();
+ probe sdap_nested_group_recv();
+
+ probe sdap_nested_group_process_send(const char *orig_dn);
+ probe sdap_nested_group_process_split_pre();
+ probe sdap_nested_group_process_split_post();
+ probe sdap_nested_group_process_recv(const char *orig_dn);
+ probe sdap_nested_group_check_cache_pre();
+ probe sdap_nested_group_check_cache_post();
+ probe sdap_nested_group_sysdb_search_users_pre();
+ probe sdap_nested_group_sysdb_search_users_post();
+ probe sdap_nested_group_sysdb_search_groups_pre();
+ probe sdap_nested_group_sysdb_search_groups_post();
+ probe sdap_nested_group_populate_search_users_pre();
+ probe sdap_nested_group_populate_search_users_post();
}
--
2.4.11
>From 250966c2abc53e5633ebaf61f847ef006dd53764 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Mon, 29 Feb 2016 16:32:24 +0100
Subject: [PATCH 07/10] CONTRIB: Add a systemtap script to analyze the
performance of the 'id' command
Run this script using "stap" as root:
sudo stap /path/to/sssd/contrib/systemtap/id_perf.stp
It is not required to restart the script between successive id runs,
the variables are cleared when systemtap detects id had started or finished.
You should see output as this one:
Total run time of id was: 112 ms
Number of zero-level cache transactions: 9
Time spent in level-0 sysdb transactions: 84 ms
Time spent writing to LDB: 80 ms
Number of LDAP searches: 13
Time spent waiting for LDAP: 11 ms
LDAP searches breakdown:
Number of user requests: 1
Time spent in user requests: 15
Number of group requests: 6
Time spent in group requests: 71
Number of initgroups requests: 1
Time spent in initgroups requests: 20
Unaccounted time: 17 ms
sysdb transaction breakdown:
1 hits of transaction sysdb_transaction_commit+0x6b [libsss_util.so]
sdap_save_users+0x2d2 [libsss_ldap_common.so]
sdap_get_users_done+0x186 [libsss_ldap_common.so]
sdap_search_user_process+0x2d9 [libsss_ldap_common.so]
generic_ext_search_handler+0x22f [libsss_ldap_common.so]
sdap_get_and_parse_generic_done+0x6f [libsss_ldap_common.so]
sdap_get_generic_op_finished+0x806 [libsss_ldap_common.so]
sdap_process_message+0x3c4 [libsss_ldap_common.so]
sdap_process_result+0x33a [libsss_ldap_common.so]
sdap_ldap_next_result+0x2f [libsss_
avg:14 min: 14 max: 14 sum: 14
5 hits of transaction sysdb_transaction_commit+0x6b [libsss_util.so]
sdap_nested_done+0x2c8 [libsss_ldap_common.so]
sdap_nested_group_done+0x9b [libsss_ldap_common.so]
0x7f47a6320be4 [libtevent.so.0.9.26+0x4be4]
avg:9 min: 9 max: 11 sum: 49
1 hits of transaction sysdb_transaction_commit+0x6b [libsss_util.so]
sdap_nested_done+0x2c8 [libsss_ldap_common.so]
sdap_nested_group_done+0x9b [libsss_ldap_common.so]
sdap_nested_group_process_done+0x1dc [libsss_ldap_common.so]
sdap_nested_group_single_done+0x112 [libsss_ldap_common.so]
sdap_nested_group_recurse_done+0x95 [libsss_ldap_common.so]
0x7f47a6320be4 [libtevent.so.0.9.26+0x4be4]
avg:11 min: 11 max: 11 sum: 11
---
Makefile.am | 5 ++
contrib/systemtap/id_perf.stp | 165 ++++++++++++++++++++++++++++++++++++++++++
2 files changed, 170 insertions(+)
create mode 100644 contrib/systemtap/id_perf.stp
diff --git a/Makefile.am b/Makefile.am
index
e0b01190cde7933fdd9cbfb617a201da85f367ab..1d21b97ff56551f680f1a4942f6a2c0bb8be31ef
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -54,6 +54,7 @@ endif
sssdconfdir = $(sysconfdir)/sssd
sssddatadir = $(datadir)/sssd
sssdapiplugindir = $(sssddatadir)/sssd.api.d
+sssdtapscriptdir = $(sssddatadir)/systemtap
dbuspolicydir = $(sysconfdir)/dbus-1/system.d
dbusservicedir = $(datadir)/dbus-1/system-services
sss_statedir = $(localstatedir)/lib/sss
@@ -1108,6 +1109,10 @@ CLEANFILES += stap_generated_probes.h \
$(NULL)
endif
+dist_sssdtapscript_DATA = \
+ contrib/systemtap/id_perf.stp \
+ $(NULL)
+
####################
# Sbus Codegen #
####################
diff --git a/contrib/systemtap/id_perf.stp b/contrib/systemtap/id_perf.stp
new file mode 100644
index
0000000000000000000000000000000000000000..0ad619506f65cc0cafc4825bc82da509a47bb011
--- /dev/null
+++ b/contrib/systemtap/id_perf.stp
@@ -0,0 +1,165 @@
+global in_id
+
+global runtime_start
+global runtime_end
+
+global num_transactions
+global time_in_transactions
+global trans_start_time
+global trans_end_time
+
+global time_in_ldb
+global ldb_start_time
+global ldb_end_time
+
+global num_ldap_searches
+global time_in_ldap
+global ldap_start_time
+global ldap_end_time
+
+global acct_req_types
+global acct_req_times
+global acct_req_rtime
+
+global bts
+
+function print_acct_req(req_type)
+{
+ str_req = acct_req_desc(req_type)
+ printf("\tNumber of %s requests: %d\n", str_req, acct_req_types[req_type])
+ printf("\tTime spent in %s requests: %d\n", str_req,
acct_req_times[req_type])
+ printf("\n")
+}
+
+function print_report()
+{
+ max_trans_time = 0
+ max_trans_time_bt = ""
+
+ total_time = runtime_end - runtime_start
+ printf("Total run time of id was: %d ms\n", total_time)
+ printf("Number of zero-level cache transactions: %d\n", num_transactions)
+ printf("Time spent in level-0 sysdb transactions: %d ms\n",
time_in_transactions)
+ printf("Time spent writing to LDB: %d ms\n", time_in_ldb)
+ printf("Number of LDAP searches: %d\n", num_ldap_searches)
+ printf("Time spent waiting for LDAP: %d ms\n", time_in_ldap)
+
+ printf("LDAP searches breakdown:\n")
+ foreach (req_type in acct_req_types) {
+ print_acct_req(req_type)
+ }
+
+ printf("Unaccounted time: %d ms\n",
+ total_time - time_in_transactions - time_in_ldap)
+
+ printf("sysdb transaction breakdown:\n")
+ foreach ([b] in bts) {
+ printf("%d hits of transaction %s\n", @count(bts[b]), b)
+ printf("avg:%d min: %d max: %d sum: %d\n\n",
+ @avg(bts[b]), @min(bts[b]), @max(bts[b]), @sum(bts[b]))
+
+ if (@max(bts[b]) > max_trans_time) {
+ max_trans_time = @max(bts[b])
+ max_trans_time_bt = b
+ }
+ }
+
+ printf("The most expensive transaction breakdown, per transaction:\n")
+ print(@hist_linear(bts[max_trans_time_bt], 0, 500, 50))
+}
+
+probe process("/usr/bin/id").begin
+{
+ in_id = 1
+
+ num_transactions = 0
+ time_in_transactions = 0
+
+ num_ldap_searches = 0
+ time_in_ldap = 0
+ time_in_ldb = 0
+
+ acct_req_types[0x0001] = 0
+ acct_req_types[0x0002] = 0
+ acct_req_types[0x0003] = 0
+
+ acct_req_times[0x0001] = 0
+ acct_req_times[0x0002] = 0
+ acct_req_times[0x0003] = 0
+
+ acct_req_rtime[0x0001] = 0
+ acct_req_rtime[0x0002] = 0
+ acct_req_rtime[0x0003] = 0
+
+ runtime_start = gettimeofday_ms()
+}
+
+probe process("/usr/bin/id").end
+{
+ in_id = 0
+
+ runtime_end = gettimeofday_ms()
+ print_report()
+
+ delete bts
+}
+
+probe sssd_transaction_start
+{
+ if (nesting == 0 && in_id == 1) {
+ num_transactions++
+ trans_start_time = gettimeofday_ms()
+ }
+}
+
+probe sssd_transaction_commit_before
+{
+ if (nesting == 0 && in_id == 1) {
+ ldb_start_time = gettimeofday_ms()
+ }
+}
+
+probe sssd_transaction_commit_after
+{
+ if (nesting == 0 && in_id == 1) {
+ ldb_end_time = gettimeofday_ms()
+ time_in_ldb += (ldb_end_time-ldb_start_time)
+
+ trans_end_time = gettimeofday_ms()
+ time_in_transactions += (trans_end_time-trans_start_time)
+
+ bt = sprint_ubacktrace()
+ bts[bt] <<< (trans_end_time-trans_start_time)
+ }
+}
+
+probe sdap_search_send
+{
+ if (in_id == 1) {
+ num_ldap_searches++
+ ldap_start_time = gettimeofday_ms()
+ }
+}
+
+probe sdap_search_recv
+{
+ if (in_id == 1) {
+ ldap_end_time = gettimeofday_ms()
+ time_in_ldap += (ldap_end_time-ldap_start_time)
+ }
+}
+
+probe sdap_acct_req_send
+{
+ if (in_id == 1) {
+ acct_req_types[entry_type]++
+ acct_req_rtime[entry_type] = gettimeofday_ms()
+ }
+}
+
+probe sdap_acct_req_recv
+{
+ if (in_id == 1) {
+ acct_req_times[entry_type] += (gettimeofday_ms() -
acct_req_rtime[entry_type])
+ }
+}
--
2.4.11
>From a579d677082f5d9fef5de3a6575107bf85858244 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Tue, 1 Mar 2016 15:35:19 +0100
Subject: [PATCH 08/10] CONTRIB: Add a systemstap script to measure nested
group code performance
When all the dependencies are installed, run the script using systemtap:
You'll see an output such as:
# stap /usr/share/sssd/systemtap/nested_group_perf.stp
^CTime spent in group sssd_be searches: 600
Time spent in sdap_nested_group_send/recv: 65 ms (ratio: 10.83%)
Time spent in zero-level sysdb transactions: 6813 ms (ratio: 1135.50%)
Breakdown of sdap_nested_group req (total: 65 ms)
sdap_nested_group_process req: 64
sdap_nested_group_process_split req: 22
sdap_nested_group_check_cache: 21
sdap_nested_group_sysdb_search_users: 10
sdap_nested_group_sysdb_search_groups: 9
ldap request breakdown of total 60
sdap_nested_group_deref req: 24
sdap_deref_search_send req 24
processing deref results: 0
sdap_nested_group_lookup_user req: 18
sdap_nested_group_lookup_group req: 0
Time spent refreshing unknown members: 18
Breakdown of results processing (total 6813)
Time spent populating nested members: 10
Time spent searching ldb while populating nested members: 5
Time spent saving nested members: 110
Time spent writing to the ldb: 678 ms
Please note that since the script is supposed to be used in scenarios such as
tracing "id" performance, which typically involve multiple group requests.
Therefore, the variables are not zeroed out and you need to interrupt the
script manually with Ctrl+C.
---
Makefile.am | 1 +
contrib/systemtap/nested_group_perf.stp | 333 ++++++++++++++++++++++++++++++++
2 files changed, 334 insertions(+)
create mode 100644 contrib/systemtap/nested_group_perf.stp
diff --git a/Makefile.am b/Makefile.am
index
1d21b97ff56551f680f1a4942f6a2c0bb8be31ef..4d1274f5cc171618fa7028966b66a0e4e135d432
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1111,6 +1111,7 @@ endif
dist_sssdtapscript_DATA = \
contrib/systemtap/id_perf.stp \
+ contrib/systemtap/nested_group_perf.stp \
$(NULL)
####################
diff --git a/contrib/systemtap/nested_group_perf.stp
b/contrib/systemtap/nested_group_perf.stp
new file mode 100644
index
0000000000000000000000000000000000000000..0c7ff033278d46f59c7025b0b38c69022bfe5704
--- /dev/null
+++ b/contrib/systemtap/nested_group_perf.stp
@@ -0,0 +1,333 @@
+global time_in_populate
+global populate_start_time
+global populate_end_time
+
+global time_in_save
+global save_start_time
+global save_end_time
+
+global time_in_groupreq
+global groupreq_start
+global groupreq_end
+
+global user_req_index = 0
+global group_req_index = 1
+global unknown_req_index = 2
+global deref_req_index = 3
+global ldap_req_times
+
+global user_req_start
+global user_req_end
+
+global group_req_start
+global group_req_end
+
+global unknown_req_start
+global unknown_req_end
+
+global deref_req_start
+global deref_req_end
+
+global time_in_deref_nested
+global deref_req_nested_start
+global deref_req_nested_end
+
+global time_in_deref_process
+global deref_req_process_start
+global deref_req_process_end
+
+global time_in_transactions
+global trans_start_time
+global trans_end_time
+
+global time_in_ldb
+global ldb_start_time
+global ldb_end_time
+
+global time_in_nested_gr_req
+global nested_gr_req_start_time
+global nested_gr_req_end_time
+
+global time_in_nested_gr_process_req
+global nested_gr_process_req_start_time
+global nested_gr_process_req_end_time
+
+global time_in_split_members
+global split_members_start
+global split_members_end
+
+global time_in_check_cache
+global check_cache_start
+global check_cache_end
+
+global time_in_search_users
+global search_users_start
+global search_users_end
+
+global time_in_search_groups
+global search_groups_start
+global search_groups_end
+
+global time_in_populate_search_users
+global populate_search_users_start
+global populate_search_users_end
+
+function print_report()
+{
+ user_req_total = @sum(ldap_req_times[user_req_index])
+ group_req_total = @sum(ldap_req_times[group_req_index])
+ unknown_req_total = @sum(ldap_req_times[unknown_req_index])
+ deref_req_total = @sum(ldap_req_times[deref_req_index])
+ all_req_total = user_req_total + group_req_total + unknown_req_total +
deref_req_total
+
+ # systemtap doesn't handle floating point numbers..
+ trans_rate = 10000 * time_in_transactions / time_in_groupreq
+ nested_rate = 10000 * time_in_nested_gr_req / time_in_groupreq
+
+ printf("Time spent in group sssd_be searches: %d\n", time_in_groupreq)
+ printf("Time spent in sdap_nested_group_send/recv: %d ms (ratio:
%d.%02d%%)\n",
+ time_in_nested_gr_req, nested_rate/100, nested_rate%100)
+ printf("Time spent in zero-level sysdb transactions: %d ms (ratio:
%d.%02d%%)\n",
+ time_in_transactions, trans_rate/100, trans_rate%100)
+ printf("\n")
+
+ printf("Breakdown of sdap_nested_group req (total: %d ms)\n",
time_in_nested_gr_req);
+ printf("\tsdap_nested_group_process req: %d\n",
time_in_nested_gr_process_req)
+ printf("\t\tsdap_nested_group_process_split req: %d\n",
time_in_split_members)
+ printf("\t\t\tsdap_nested_group_check_cache: %d\n", time_in_check_cache)
+ printf("\t\t\t\tsdap_nested_group_sysdb_search_users: %d\n",
time_in_search_users)
+ printf("\t\t\t\tsdap_nested_group_sysdb_search_groups: %d\n",
time_in_search_groups)
+ printf("\t\tldap request breakdown of total %d\n", all_req_total)
+ printf("\t\t\tsdap_nested_group_deref req: %d\n", time_in_deref_nested)
+ printf("\t\t\t\tsdap_deref_search_send req %d\n", deref_req_total)
+ printf("\t\t\t\tprocessing deref results: %d\n", time_in_deref_process)
+ printf("\t\t\tsdap_nested_group_lookup_user req: %d\n", user_req_total)
+ printf("\t\t\tsdap_nested_group_lookup_group req: %d\n", group_req_total)
+ printf("\t\t\tTime spent refreshing unknown members: %d\n",
unknown_req_total)
+ printf("\n")
+
+ printf("Breakdown of results processing (total %d)\n",
time_in_transactions);
+ printf("\tTime spent populating nested members: %d\n", time_in_populate)
+ printf("\t\tTime spent searching ldb while populating nested members:
%d\n", time_in_populate_search_users)
+ printf("\tTime spent saving nested members: %d\n", time_in_save)
+ printf("\tTime spent writing to the ldb: %d ms\n", time_in_ldb)
+ printf("\n")
+}
+
+probe sssd_transaction_start
+{
+ if (nesting == 0) {
+ num_transactions++
+ trans_start_time = gettimeofday_ms()
+ }
+}
+
+probe sssd_transaction_commit_before
+{
+ if (nesting == 0) {
+ ldb_start_time = gettimeofday_ms()
+ }
+}
+
+probe sssd_transaction_commit_after
+{
+ if (nesting == 0) {
+ trans_end_time = gettimeofday_ms()
+ time_in_transactions += (trans_end_time-trans_start_time)
+
+ ldb_end_time = gettimeofday_ms()
+ time_in_ldb += (ldb_end_time - ldb_start_time)
+ }
+}
+
+probe sdap_deref_send
+{
+ deref_req_start = gettimeofday_ms()
+}
+
+probe sdap_deref_recv
+{
+ deref_req_end = gettimeofday_ms()
+ ldap_req_times[deref_req_index] <<< (deref_req_end - deref_req_start)
+}
+
+probe sdap_nested_group_lookup_user_send
+{
+ user_req_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_lookup_user_recv
+{
+ user_req_end = gettimeofday_ms()
+ ldap_req_times[user_req_index] <<< (user_req_end - user_req_start)
+}
+
+probe sdap_nested_group_lookup_group_send
+{
+ group_req_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_lookup_group_recv
+{
+ group_req_end = gettimeofday_ms()
+ ldap_req_times[group_req_index] <<< (group_req_end - group_req_start)
+}
+
+probe sdap_nested_group_lookup_unknown_send
+{
+ unknown_req_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_lookup_unknown_recv
+{
+ unknown_req_end = gettimeofday_ms()
+ ldap_req_times[unknown_req_index] <<< (unknown_req_end - unknown_req_start)
+}
+
+probe sdap_nested_group_deref_send
+{
+ deref_req_nested_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_deref_recv
+{
+ deref_req_nested_end = gettimeofday_ms()
+ time_in_deref_nested += (deref_req_nested_end - deref_req_nested_start)
+}
+
+probe sdap_nested_group_deref_process_pre
+{
+ deref_req_process_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_deref_process_post
+{
+ deref_req_process_end = gettimeofday_ms()
+ time_in_deref_process += (deref_req_process_end - deref_req_process_start)
+}
+
+probe sdap_nested_group_populate_pre
+{
+ populate_start_time = gettimeofday_ms()
+}
+
+probe sdap_nested_group_populate_post
+{
+ populate_end_time = gettimeofday_ms()
+ time_in_populate += (populate_end_time - populate_start_time)
+}
+
+probe sdap_nested_group_save_pre
+{
+ save_start_time = gettimeofday_ms()
+}
+
+probe sdap_nested_group_save_post
+{
+ save_end_time = gettimeofday_ms()
+ time_in_save += (save_end_time - save_start_time)
+}
+
+probe sdap_nested_group_send
+{
+ nested_gr_req_start_time = gettimeofday_ms()
+}
+
+probe sdap_nested_group_recv
+{
+ nested_gr_req_end_time = gettimeofday_ms()
+ time_in_nested_gr_req += (nested_gr_req_end_time -
nested_gr_req_start_time)
+}
+
+probe sdap_nested_group_process_send
+{
+ nested_gr_process_req_start_time = gettimeofday_ms()
+}
+
+probe sdap_nested_group_process_recv
+{
+ nested_gr_process_req_end_time = gettimeofday_ms()
+ time_in_nested_gr_process_req += (nested_gr_process_req_end_time -
nested_gr_process_req_start_time)
+}
+
+probe sdap_nested_group_process_split_pre
+{
+ split_members_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_process_split_post
+{
+ split_members_end = gettimeofday_ms()
+ time_in_split_members += (split_members_end - split_members_start)
+}
+
+probe sdap_nested_group_check_cache_pre
+{
+ check_cache_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_check_cache_post
+{
+ check_cache_end = gettimeofday_ms()
+ time_in_check_cache += (check_cache_end - check_cache_start)
+}
+
+probe sdap_nested_group_sysdb_search_users_pre
+{
+ search_users_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_sysdb_search_users_post
+{
+ search_users_end = gettimeofday_ms()
+ time_in_search_users += (search_users_end - search_users_start)
+}
+
+probe sdap_nested_group_sysdb_search_groups_pre
+{
+ search_groups_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_sysdb_search_groups_post
+{
+ search_groups_end = gettimeofday_ms()
+ time_in_search_groups += (search_groups_end - search_groups_start)
+}
+
+probe sdap_nested_group_populate_search_users_pre
+{
+ populate_search_users_start = gettimeofday_ms()
+}
+
+probe sdap_nested_group_populate_search_users_post
+{
+ populate_search_users_end = gettimeofday_ms()
+ time_in_populate_search_users += (populate_search_users_end -
populate_search_users_start)
+}
+
+probe sdap_acct_req_send
+{
+ if (entry_type == 0x0002) {
+ groupreq_start = gettimeofday_ms()
+ }
+}
+
+probe sdap_acct_req_recv
+{
+ if (entry_type == 0x0002) {
+ groupreq_end = gettimeofday_ms()
+ time_in_groupreq += (groupreq_end - groupreq_start)
+ }
+}
+
+probe begin
+{
+ time_in_populate = 0
+ time_in_save = 0
+ time_in_transactions = 0
+}
+
+probe end
+{
+ print_report()
+}
--
2.4.11
>From ce9ae733daa1a7fb38fd68b9cf669eea0bf1656d Mon Sep 17 00:00:00 2001
From: Lukas Slebodnik <[email protected]>
Date: Fri, 6 May 2016 15:50:25 +0200
Subject: [PATCH 09/10] CI: Exclude files in /tmp during coverage runs
Exclude files from /tmp during coverage generation to avoid issues with
(presumably) files generated by dtrace that couldn't otherwise be opened
or parsed.
---
contrib/ci/run | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/contrib/ci/run b/contrib/ci/run
index
3c8f502f82f6a3c7ca7021e4f8d55759e78542a2..5f067bc7c5d862a68a358bb64a3ae6c0e0eba706
100755
--- a/contrib/ci/run
+++ b/contrib/ci/run
@@ -298,7 +298,7 @@ function build_coverage()
--add-tracefile ci-check.info \
--output-file ci-dirty.info
stage lcov-clean lcov --remove ci-dirty.info \
- "/usr/*" "src/tests/*" \
+ "/usr/*" "src/tests/*" "/tmp/*" \
--output-file ci.info
stage genhtml eval 'genhtml --output-directory \
"$coverage_report_dir" \
--
2.4.11
>From 4a929f90a6721b49d32002b30ac4c09f280f003c Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <[email protected]>
Date: Fri, 6 May 2016 15:51:12 +0200
Subject: [PATCH 10/10] BUILD: Enable systemtap during RPM build and CI
So far, systemtap is only enabled for Red Hat distributions.
---
contrib/ci/configure.sh | 6 ++++++
contrib/sssd.spec.in | 19 +++++++++++++++++++
2 files changed, 25 insertions(+)
diff --git a/contrib/ci/configure.sh b/contrib/ci/configure.sh
index
c850eb9ce9a4228c1a89b8b2b49311e1c748b7de..823d3277c0467d1abf0e746c910d2a0e16783693
100644
--- a/contrib/ci/configure.sh
+++ b/contrib/ci/configure.sh
@@ -47,6 +47,12 @@ if [[ "$DISTRO_BRANCH" == -redhat-redhatenterprise*-7.*- ||
)
fi
+if [[ "$DISTRO_FAMILY" == "redhat" ]]; then
+ CONFIGURE_ARG_LIST+=(
+ "--enable-systemtap"
+ )
+fi
+
declare -r -a CONFIGURE_ARG_LIST
fi # _CONFIGURE_SH
diff --git a/contrib/sssd.spec.in b/contrib/sssd.spec.in
index
2ba6a4d4c919a0697b18c4293f5e33e12b996cac..a18599f157a2459fd0e6b47fdca32ddc0bf626a6
100644
--- a/contrib/sssd.spec.in
+++ b/contrib/sssd.spec.in
@@ -63,6 +63,11 @@
%global with_python3_option --without-python3-bindings
%endif
+%global enable_systemtap 1
+%if (0%{?enable_systemtap} == 1)
+ %global enable_systemtap_opt --enable-systemtap
+%endif
+
Name: @PACKAGE_NAME@
Version: @PACKAGE_VERSION@
Release: 0@PRERELEASE_VERSION@%{?dist}
@@ -160,6 +165,10 @@ BuildRequires: nfs-utils-lib-devel
BuildRequires: samba4-devel
BuildRequires: libsmbclient-devel
+%if (0%{?enable_systemtap} == 1)
+BuildRequires: systemtap-sdt-devel
+%endif
+
%description
Provides a set of daemons to manage access to remote directories and
authentication mechanisms. It provides an NSS and PAM interface toward
@@ -596,6 +605,7 @@ autoreconf -ivf
%{?with_cifs_utils_plugin_option} \
%{?with_python3_option} \
%{?enable_polkit_rules_option} \
+ %{?enable_systemtap_opt} \
%{?experimental}
make %{?_smp_mflags} all
@@ -776,6 +786,15 @@ done
%{_mandir}/man5/sss_rpcidmapd.5*
%{_mandir}/man8/sssd.8*
%{_mandir}/man8/sss_cache.8*
+%if (0%{?enable_systemtap} == 1)
+%dir %{_datadir}/sssd/systemtap
+%{_datadir}/sssd/systemtap/id_perf.stp
+%{_datadir}/sssd/systemtap/nested_group_perf.stp
+%dir %{_datadir}/systemtap
+%dir %{_datadir}/systemtap/tapset
+%{_datadir}/systemtap/tapset/sssd.stp
+%{_datadir}/systemtap/tapset/sssd_functions.stp
+%endif
%if (0%{?install_pcscd_polkit_rule} == 1)
%files polkit-rules
--
2.4.11
_______________________________________________
sssd-devel mailing list
[email protected]
https://lists.fedorahosted.org/admin/lists/[email protected]
