sssd/0112-CONTRIB-Add-DP-Request-analysis-script.patch
Lukas Slebodnik 8eda442b2e Fix few bugs/regressions
Resolves: rhbz#1488327 - SELinux is preventing selinux_child from write access
                         on the sock_file system_bus_socket
Resolves: rhbz#1490402 - SSSD does not create /var/lib/sss/deskprofile and
                         fails to download desktop profile data
Resolves: upstream#3485 - getsidbyid does not work with 1.15.3
Resolves: upstream#3488 - SUDO doesn't work for IPA users on IPA clients after
                          applying ID Views for them in IPA server
Resolves: upstream#3501 - Accessing IdM kerberos ticket fails while id mapping
                          is applied
2017-09-12 09:22:07 +02:00

143 lines
4.5 KiB
Diff

From 1182dd93a5a6bb18943284273f7fd59b83468843 Mon Sep 17 00:00:00 2001
From: Justin Stephenson <jstephen@redhat.com>
Date: Fri, 5 May 2017 12:13:19 -0400
Subject: [PATCH 112/115] CONTRIB: Add DP Request analysis script
Run this script using stap as root and Ctrl-C to print the summary
report
stap -v /usr/share/sssd/systemtap/dp_request.stp
This script will use the data provider request probe markers to provide
elapsed time of each request and more information about the slowest
request in the summary report.
Resolves:
https://pagure.io/SSSD/sssd/issue/3061
Reviewed-by: Jakub Hrozek <jhrozek@redhat.com>
---
Makefile.am | 1 +
contrib/sssd.spec.in | 1 +
contrib/systemtap/dp_request.stp | 85 ++++++++++++++++++++++++++++++++++++++++
3 files changed, 87 insertions(+)
create mode 100644 contrib/systemtap/dp_request.stp
diff --git a/Makefile.am b/Makefile.am
index f61560135f3bf233a71bf219c4a773d3dcc03ab0..f99649e924672ceeba8d8653178030e6d1805f4a 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -1257,6 +1257,7 @@ dist_systemtap_tap_DATA = \
dist_sssdtapscript_DATA = \
contrib/systemtap/id_perf.stp \
contrib/systemtap/nested_group_perf.stp \
+ contrib/systemtap/dp_request.stp \
$(NULL)
stap_generated_probes.h: $(srcdir)/src/systemtap/sssd_probes.d
diff --git a/contrib/sssd.spec.in b/contrib/sssd.spec.in
index 43b853bb523bb212316f3d0046da6b88e4505ad2..e921a352eee6c9a6584292ba8ae5fad1639db57d 100644
--- a/contrib/sssd.spec.in
+++ b/contrib/sssd.spec.in
@@ -1003,6 +1003,7 @@ done
%dir %{_datadir}/sssd/systemtap
%{_datadir}/sssd/systemtap/id_perf.stp
%{_datadir}/sssd/systemtap/nested_group_perf.stp
+%{_datadir}/sssd/systemtap/dp_request.stp
%dir %{_datadir}/systemtap
%dir %{_datadir}/systemtap/tapset
%{_datadir}/systemtap/tapset/sssd.stp
diff --git a/contrib/systemtap/dp_request.stp b/contrib/systemtap/dp_request.stp
new file mode 100644
index 0000000000000000000000000000000000000000..0fa108263e297bca94673414b057b7320334a369
--- /dev/null
+++ b/contrib/systemtap/dp_request.stp
@@ -0,0 +1,85 @@
+/* Start Run with:
+ * stap -v dp_request.stp
+ *
+ * Then reproduce slow login or id/getent in another terminal.
+ * Ctrl-C running stap once login completes.
+ *
+ * Probe tapsets are in /usr/share/systemtap/tapset/sssd.stp
+ */
+
+
+global num_dp_requests
+
+global time_in_dp_req
+global elapsed_time
+global dp_req_send_start
+global dp_req_send_end
+
+/* Used for tracking slowest request as tz_ctime() only converts seconds, not ms */
+global dp_req_send_sec_start
+global dp_req_send_sec_end
+
+global slowest_req_name
+global slowest_req_target
+global slowest_req_method
+global slowest_req_time = 0
+global slowest_req_start_time
+global slowest_req_end_time
+
+function print_report()
+{
+ printf("\nEnding Systemtap Run - Providing Summary\n")
+ printf("Total Number of DP requests: [%d]\n", num_dp_requests)
+ printf("Total time in DP requests: [%s]\n", msecs_to_string(time_in_dp_req))
+ printf("Slowest request data:\n")
+ printf("\tRequest: [%s]\n", slowest_req_name)
+ printf("\tTarget: [%s]\n", dp_target_str(slowest_req_target))
+ printf("\tMethod: [%s]\n", dp_method_str(slowest_req_method))
+ printf("\tStart Time: [%s]\n", tz_ctime(slowest_req_start_time))
+ printf("\tEnd Time: [%s]\n", tz_ctime(slowest_req_end_time))
+ printf("\tDuration: [%s]\n\n", msecs_to_string(slowest_req_time))
+}
+
+probe dp_req_send
+{
+ dp_req_send_start = gettimeofday_ms()
+ dp_req_send_sec_start = gettimeofday_s()
+
+ printf("\t--> DP Request [%s] sent for domain [%s]\n", dp_req_name, dp_req_domain)
+ printf("\t--> Target: [%s] - Method: [%s]\n", dp_target_str(dp_req_target), dp_method_str(dp_req_method))
+
+ num_dp_requests++
+}
+
+probe dp_req_done
+{
+ dp_req_send_end = gettimeofday_ms()
+ dp_req_send_sec_end = gettimeofday_s()
+ elapsed_time = (dp_req_send_end - dp_req_send_start)
+
+ printf("\t\t DP Request [%s] finished with return code [%d]: [%s]\n",
+ dp_req_name, dp_ret, dp_errorstr)
+ printf("\t\t Elapsed time [%s]\n\n", msecs_to_string(elapsed_time))
+
+ /* Track slowest request information */
+ if (elapsed_time > slowest_req_time) {
+ slowest_req_time = elapsed_time
+ slowest_req_name = dp_req_name
+ slowest_req_method = dp_req_method
+ slowest_req_target = slowest_req_target
+ slowest_req_start_time = dp_req_send_sec_start
+ slowest_req_end_time = dp_req_send_sec_end
+ }
+
+ time_in_dp_req += (dp_req_send_end - dp_req_send_start)
+}
+
+probe begin
+{
+ printf("\t*** Beginning run! ***\n")
+}
+
+probe end
+{
+ print_report()
+}
--
2.14.1