On Mon, May 09, 2016 at 10:04:37AM +0200, Jakub Hrozek wrote:
> 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)
Hi,
the attached patches just fix a Coverity issue in one of the patches.
>From dc6e4aabf78fd2424aaeea9dac41b5bdf7e1bea7 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
390e58938b123a4043edec3bc4dea0230c0fd298..5adc575c5159965bdde0bcd4b4443cca7f70f501
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -682,6 +682,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 2e6de9cf0278525e61af915220b8bdcf667abb13 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
5adc575c5159965bdde0bcd4b4443cca7f70f501..33930759ab82b65643a9a0a071fd92b025dab145
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
@@ -403,6 +405,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)
###############################
@@ -895,6 +898,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
@@ -1067,6 +1073,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 #
####################
@@ -1099,7 +1138,7 @@ CODEGEN_CODE = \
$(CODEGEN_CODE): $(SBUS_CODEGEN)
-BUILT_SOURCES = $(CODEGEN_CODE)
+BUILT_SOURCES += $(CODEGEN_CODE)
####################
# Program Binaries #
@@ -3779,7 +3818,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
a5afb8c020ee00b680aac0680bcf6f6495dd8222..abf50a56f3a9b5e24759e819b24ba01d65192f37
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 77dad909fe79d6aaa7aa90e810cb9bb2ddc240ad Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
3c888a42ca6f3b3e37b9f63e35c31bb7d5ffc367..f9b9b3ff864eef187eb0d3d79796e4000e56addf
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
4b1667ca41ca570851d5841aeb441dddd09cd2cf..d0837fe232425a61a932ce81ff8ba1b0fe4bafc6
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 c1a4fba84679bb4ce10badcc9458088e4a94d281 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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 | 8 ++++++++
src/systemtap/sssd.stp.in | 32 ++++++++++++++++++++++++++++++++
src/systemtap/sssd_probes.d | 4 ++++
5 files changed, 48 insertions(+), 1 deletion(-)
create mode 100644 src/systemtap/sssd.stp.in
diff --git a/Makefile.am b/Makefile.am
index
33930759ab82b65643a9a0a071fd92b025dab145..1b4ba3cc651b29c55f7b43c90bc479f584a911e2
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -81,6 +81,7 @@ krb5rcachedir = @krb5rcachedir@
sudolibdir = @sudolibpath@
polkitdir = @polkitdir@
pamconfdir = $(sysconfdir)/pam.d
+systemtap_tapdir = @tapset_dir@
UNICODE_LIBS=@UNICODE_LIBS@
@@ -1081,6 +1082,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 $@
@@ -1103,7 +1106,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
f9b9b3ff864eef187eb0d3d79796e4000e56addf..dca8332e2d313dc53f334337ff41d1bcb503b9be
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,
@@ -907,10 +909,15 @@ int sysdb_transaction_start(struct sysdb_ctx *sysdb)
int sysdb_transaction_commit(struct sysdb_ctx *sysdb)
{
int ret;
+#ifdef HAVE_SYSTEMTAP
+ int commit_nesting = sysdb->transaction_nesting-1;
+#endif
+ PROBE(SYSDB_TRANSACTION_COMMIT_BEFORE, commit_nesting);
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 +932,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 b3c72382cea5cb3e3ca094fd444197cbe32ec87e Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
1b4ba3cc651b29c55f7b43c90bc479f584a911e2..254d5446c5f8aca4674a216544cf5a07334e6519
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1082,7 +1082,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 24e57c1ed2b76350389d6cb5e329fa32bb7335b3 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
254d5446c5f8aca4674a216544cf5a07334e6519..00f04d74fe72d308b3b17a7343d11f981328b8c1
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -2176,6 +2176,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
@@ -2995,6 +2998,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 84a823dd0fd5d62fbe56d3f27cacf83c27a66ca5 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
00f04d74fe72d308b3b17a7343d11f981328b8c1..3c4b0646afd64a6cd64d1acbadb90d0c2115c0aa
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -55,6 +55,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
@@ -1111,6 +1112,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 9cc3ee68ab082979b4d30f7addc94a683aad4308 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
3c4b0646afd64a6cd64d1acbadb90d0c2115c0aa..3a9858fcfc1c2c9564e881cd4bd8e322ee0cd087
100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1114,6 +1114,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 4b7caf560c555a6f7a8b75a2cb9e85cb07cbc80e Mon Sep 17 00:00:00 2001
From: Lukas Slebodnik <lsleb...@redhat.com>
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 def7601820c687c55db87136f77ce1cd06affa29 Mon Sep 17 00:00:00 2001
From: Jakub Hrozek <jhro...@redhat.com>
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
355b9510994b2f5ea470febca670d8982ad4bfce..2a244a6b4d9768b7aa5daaa095dd46cb9059a306
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
@@ -779,6 +789,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
sssd-devel@lists.fedorahosted.org
https://lists.fedorahosted.org/admin/lists/sssd-devel@lists.fedorahosted.org
