From 38eb8a68a2817b040e31c577a9e3a81b52897816 Mon Sep 17 00:00:00 2001 From: Francis Deslauriers Date: Mon, 31 Aug 2020 11:05:41 -0400 Subject: [PATCH] Tests: event notifier error counters MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Signed-off-by: Francis Deslauriers Signed-off-by: Jérémie Galarneau Change-Id: I9e2a4bab833d9204717029c1d5f594455c2262ce --- .gitignore | 1 + src/bin/lttng-sessiond/Makefile.am | 2 + src/bin/lttng-sessiond/notification-thread.c | 19 ++ src/bin/lttng-sessiond/testpoint.h | 2 + tests/regression/Makefile.am | 1 + .../regression/tools/notification/Makefile.am | 20 +- .../notification/default_pipe_size_getter.c | 53 ++++ .../tools/notification/sessiond_testpoints.c | 112 ++++++++ ...test_notification_notifier_discarded_count | 264 ++++++++++++++++++ tests/utils/utils.sh | 5 + 10 files changed, 476 insertions(+), 3 deletions(-) create mode 100644 tests/regression/tools/notification/default_pipe_size_getter.c create mode 100644 tests/regression/tools/notification/sessiond_testpoints.c create mode 100755 tests/regression/tools/notification/test_notification_notifier_discarded_count diff --git a/.gitignore b/.gitignore index 5e2b0a189..2c1bcd535 100644 --- a/.gitignore +++ b/.gitignore @@ -110,6 +110,7 @@ health_check /tests/regression/tools/notification/notification /tests/regression/tools/rotation/schedule_api /tests/regression/tools/notification/rotation +/tests/regression/tools/notification/default_pipe_size_getter /tests/regression/tools/trigger/utils/notification-client /tests/regression/ust/overlap/demo/demo /tests/regression/ust/linking/demo_builtin diff --git a/src/bin/lttng-sessiond/Makefile.am b/src/bin/lttng-sessiond/Makefile.am index e3ee7612d..8a299fab8 100644 --- a/src/bin/lttng-sessiond/Makefile.am +++ b/src/bin/lttng-sessiond/Makefile.am @@ -58,6 +58,8 @@ lttng_sessiond_SOURCES = utils.c utils.h \ event-notifier-error-accounting.c event-notifier-error-accounting.h \ action-executor.c action-executor.h +lttng_sessiond_LDFLAGS = -rdynamic + if HAVE_LIBLTTNG_UST_CTL lttng_sessiond_SOURCES += trace-ust.c ust-registry.c ust-app.c \ ust-consumer.c ust-consumer.h notify-apps.c \ diff --git a/src/bin/lttng-sessiond/notification-thread.c b/src/bin/lttng-sessiond/notification-thread.c index dd1dc3e8f..580168296 100644 --- a/src/bin/lttng-sessiond/notification-thread.c +++ b/src/bin/lttng-sessiond/notification-thread.c @@ -27,6 +27,7 @@ #include "lttng-sessiond.h" #include "health-sessiond.h" #include "thread.h" +#include "testpoint.h" #include "kernel.h" #include @@ -35,6 +36,8 @@ #include #include + +int notifier_consumption_paused; /* * Destroy the thread data previously created by the init function. */ @@ -574,6 +577,17 @@ static int handle_event_notification_pipe(int event_source_fd, goto end; } + if (testpoint(sessiond_handle_notifier_event_pipe)) { + ret = 0; + goto end; + } + + if (caa_unlikely(notifier_consumption_paused)) { + DBG("Event notifier notification consumption paused, sleeping..."); + sleep(1); + goto end; + } + ret = handle_notification_thread_event_notification( state, event_source_fd, domain); if (ret) { @@ -582,6 +596,7 @@ static int handle_event_notification_pipe(int event_source_fd, ret = -1; goto end; } + end: return ret; } @@ -640,6 +655,10 @@ void *thread_notification(void *data) goto end; } + if (testpoint(sessiond_thread_notification)) { + goto end; + } + while (true) { int fd_count, i; diff --git a/src/bin/lttng-sessiond/testpoint.h b/src/bin/lttng-sessiond/testpoint.h index 8524e1fd3..2ddd66283 100644 --- a/src/bin/lttng-sessiond/testpoint.h +++ b/src/bin/lttng-sessiond/testpoint.h @@ -22,5 +22,7 @@ TESTPOINT_DECL(sessiond_thread_manage_consumer); TESTPOINT_DECL(sessiond_thread_ht_cleanup); TESTPOINT_DECL(sessiond_thread_app_manage_notify); TESTPOINT_DECL(sessiond_thread_app_reg_dispatch); +TESTPOINT_DECL(sessiond_thread_notification); +TESTPOINT_DECL(sessiond_handle_notifier_event_pipe); #endif /* SESSIOND_TESTPOINT_H */ diff --git a/tests/regression/Makefile.am b/tests/regression/Makefile.am index ca39c85e7..6aab423eb 100644 --- a/tests/regression/Makefile.am +++ b/tests/regression/Makefile.am @@ -36,6 +36,7 @@ TESTS = tools/filtering/test_invalid_filter \ tools/notification/test_notification_kernel_capture \ tools/notification/test_notification_kernel_instrumentation \ tools/notification/test_notification_kernel_syscall \ + tools/notification/test_notification_notifier_discarded_count \ tools/notification/test_notification_kernel_userspace_probe \ tools/notification/test_notification_multi_app \ tools/rotation/test_ust \ diff --git a/tests/regression/tools/notification/Makefile.am b/tests/regression/tools/notification/Makefile.am index 84acf3d3d..84e75d307 100644 --- a/tests/regression/tools/notification/Makefile.am +++ b/tests/regression/tools/notification/Makefile.am @@ -5,14 +5,15 @@ AM_CFLAGS += -I$(top_srcdir)/tests/utils LIBTAP=$(top_builddir)/tests/utils/tap/libtap.la LIB_LTTNG_CTL = $(top_builddir)/src/lib/lttng-ctl/liblttng-ctl.la -noinst_PROGRAMS = base_client notification rotation +noinst_PROGRAMS = base_client notification rotation default_pipe_size_getter if NO_SHARED -CLEANFILES = libpause_consumer.so libpause_consumer.so.debug +CLEANFILES = libpause_consumer.so libpause_consumer.so.debug libpause_sessiond.so libpause_sessiond.so.debug EXTRA_DIST = \ base_client.c \ consumer_testpoints.c \ + sessiond_testpoints.c \ notification.c \ test_notification_kernel_buffer_usage \ test_notification_kernel_capture \ @@ -21,6 +22,7 @@ EXTRA_DIST = \ test_notification_kernel_syscall \ test_notification_kernel_userspace_probe \ test_notification_multi_app \ + test_notification_notifier_discarded_count \ test_notification_ust_buffer_usage \ test_notification_ust_capture \ test_notification_ust_error \ @@ -40,7 +42,14 @@ libpause_consumer_la_LIBADD = \ $(top_builddir)/src/lib/lttng-ctl/liblttng-ctl.la \ $(DL_LIBS) libpause_consumer_la_LDFLAGS = $(FORCE_SHARED_LIB_OPTIONS) -noinst_LTLIBRARIES = libpause_consumer.la + +libpause_sessiond_la_SOURCES = sessiond_testpoints.c +libpause_sessiond_la_LIBADD = \ + $(top_builddir)/src/common/libcommon.la \ + $(top_builddir)/src/lib/lttng-ctl/liblttng-ctl.la \ + $(DL_LIBS) +libpause_sessiond_la_LDFLAGS = $(FORCE_SHARED_LIB_OPTIONS) +noinst_LTLIBRARIES = libpause_sessiond.la libpause_consumer.la base_client_SOURCES = base_client.c base_client_LDADD = $(LIB_LTTNG_CTL) @@ -51,6 +60,9 @@ notification_LDADD = $(LIB_LTTNG_CTL) $(LIBTAP) -lm rotation_SOURCES = rotation.c rotation_LDADD = $(LIB_LTTNG_CTL) $(LIBTAP) -lm +default_pipe_size_getter_SOURCES = default_pipe_size_getter.c +default_pipe_size_getter_LDADD = $(top_builddir)/src/common/libcommon.la + noinst_SCRIPTS = \ test_notification_kernel_buffer_usage \ test_notification_kernel_error \ @@ -58,6 +70,7 @@ noinst_SCRIPTS = \ test_notification_kernel_syscall \ test_notification_kernel_userspace_probe \ test_notification_multi_app \ + test_notification_notifier_discarded_count \ test_notification_ust_buffer_usage \ test_notification_ust_error \ test_notification_ust_event_rule_condition_exclusion \ @@ -72,6 +85,7 @@ EXTRA_DIST = \ test_notification_kernel_syscall \ test_notification_kernel_userspace_probe \ test_notification_multi_app \ + test_notification_notifier_discarded_count \ test_notification_ust_buffer_usage \ test_notification_ust_capture \ test_notification_ust_error \ diff --git a/tests/regression/tools/notification/default_pipe_size_getter.c b/tests/regression/tools/notification/default_pipe_size_getter.c new file mode 100644 index 000000000..cc24cec1e --- /dev/null +++ b/tests/regression/tools/notification/default_pipe_size_getter.c @@ -0,0 +1,53 @@ +/* + * default_pipe_size_getter.c + * + * Tests suite for LTTng notification API (get default size of pipes) + * + * Copyright (C) 2021 Jérémie Galarneau + * + * SPDX-License-Identifier: MIT + * + */ + +#include +#include +#include +#include + +#include +#include + +int lttng_opt_verbose; +int lttng_opt_mi; +int lttng_opt_quiet; + +int main(int argc, const char **argv) +{ + int ret; + /* + * The event notifier pipes are not "special"; they are created using + * the lttng_pipe utility. Hence, this should be representative of a + * pipe created by the session daemon for event notifier messages to + * go through. + */ + struct lttng_pipe *pipe = lttng_pipe_open(0); + + if (!pipe) { + /* lttng_pipe_open already logs on error. */ + ret = EXIT_FAILURE; + goto end; + } + + ret = fcntl(lttng_pipe_get_writefd(pipe), F_GETPIPE_SZ); + if (ret < 0) { + PERROR("Failed to get the size of the pipe"); + ret = EXIT_FAILURE; + goto end; + } + + printf("%d\n", ret); + ret = EXIT_SUCCESS; +end: + lttng_pipe_destroy(pipe); + return ret; +} diff --git a/tests/regression/tools/notification/sessiond_testpoints.c b/tests/regression/tools/notification/sessiond_testpoints.c new file mode 100644 index 000000000..c4100998d --- /dev/null +++ b/tests/regression/tools/notification/sessiond_testpoints.c @@ -0,0 +1,112 @@ +/* + * Copyright (C) 2017 Jérémie Galarneau + * Copyright (C) 2020 Francis Deslauriers + * + * SPDX-License-Identifier: GPL-2.0-only + * + */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include +#include + +static char *pause_pipe_path; +static struct lttng_pipe *pause_pipe; +static int *notifier_notif_consumption_state;; + +int lttng_opt_verbose; +int lttng_opt_mi; +int lttng_opt_quiet; + +static +void __attribute__((destructor)) pause_pipe_fini(void) +{ + int ret; + + if (pause_pipe_path) { + ret = unlink(pause_pipe_path); + if (ret) { + PERROR("Failed to unlink pause pipe: path = %s", + pause_pipe_path); + } + } + + free(pause_pipe_path); + lttng_pipe_destroy(pause_pipe); +} + +int __testpoint_sessiond_thread_notification(void); +int __testpoint_sessiond_thread_notification(void) +{ + int ret = 0; + const char *pause_pipe_path_prefix; + + pause_pipe_path_prefix = lttng_secure_getenv( + "NOTIFIER_PAUSE_PIPE_PATH"); + if (!pause_pipe_path_prefix) { + ret = -1; + goto end; + } + + notifier_notif_consumption_state = dlsym(NULL, "notifier_consumption_paused"); + assert(notifier_notif_consumption_state); + + ret = asprintf(&pause_pipe_path, "%s", pause_pipe_path_prefix); + if (ret < 1) { + ERR("Failed to allocate pause pipe path"); + goto end; + } + + DBG("Creating pause pipe at %s", pause_pipe_path); + pause_pipe = lttng_pipe_named_open(pause_pipe_path, + S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP, O_NONBLOCK); + if (!pause_pipe) { + ERR("Failed to create pause pipe at %s", pause_pipe_path); + ret = -1; + goto end; + } + + /* Only the read end of the pipe is useful to us. */ + ret = lttng_pipe_write_close(pause_pipe); +end: + return ret; +} + +int __testpoint_sessiond_handle_notifier_event_pipe(void); +int __testpoint_sessiond_handle_notifier_event_pipe(void) +{ + int ret = 0; + uint8_t value; + bool value_read = false; + + if (!pause_pipe) { + ret = -1; + goto end; + } + + /* Purge pipe and only consider the freshest value. */ + do { + ret = lttng_pipe_read(pause_pipe, &value, sizeof(value)); + if (ret == sizeof(value)) { + value_read = true; + } + } while (ret == sizeof(value)); + + ret = (errno == EAGAIN) ? 0 : -errno; + + if (value_read) { + *notifier_notif_consumption_state = !!value; + DBG("Message received on pause pipe: %s data consumption", + *notifier_notif_consumption_state ? "paused" : "resumed"); + } +end: + return ret; +} diff --git a/tests/regression/tools/notification/test_notification_notifier_discarded_count b/tests/regression/tools/notification/test_notification_notifier_discarded_count new file mode 100755 index 000000000..e49d35528 --- /dev/null +++ b/tests/regression/tools/notification/test_notification_notifier_discarded_count @@ -0,0 +1,264 @@ +#!/bin/bash +# +# Copyright (C) 2020 Francis Deslauriers +# +# SPDX-License-Identifier: LGPL-2.1-only + +CURDIR=$(dirname "$0")/ +TESTDIR=$CURDIR/../../../ + +TMPDIR=$(mktemp -d) + +TESTAPP_PATH="$TESTDIR/utils/testapp" +TESTAPP_NAME="gen-ust-events" +TESTAPP_BIN="$TESTAPP_PATH/$TESTAPP_NAME/$TESTAPP_NAME" + +TESTPOINT_BASE_PATH=$(readlink -f "$TMPDIR/lttng.t_p_n") +TESTPOINT_PIPE_PATH=$(mktemp -u "${TESTPOINT_BASE_PATH}.XXXXXX") +TESTPOINT=$(readlink -f "${CURDIR}/.libs/libpause_sessiond.so") + +SH_TAP=1 + +# shellcheck source=../../../utils/utils.sh +source "$TESTDIR/utils/utils.sh" +# shellcheck source=./util_event_generator.sh +source "$CURDIR/util_event_generator.sh" + +FULL_LTTNG_BIN="${TESTDIR}/../src/bin/lttng/${LTTNG_BIN}" +FULL_LTTNG_SESSIOND_BIN="${TESTDIR}/../src/bin/lttng-sessiond/lttng-sessiond" + +UST_NUM_TESTS=16 +KERNEL_NUM_TESTS=15 +NUM_TESTS=$(($UST_NUM_TESTS + $KERNEL_NUM_TESTS)) + +plan_tests $NUM_TESTS + +function test_kernel_notifier_discarded_count +{ + local sessiond_pipe=() + local trigger_name="my_trigger" + local list_triggers_stdout=$(mktemp -t list_triggers_stdout.XXXXXX) + + # Used on sessiond launch. + LTTNG_SESSIOND_ENV_VARS="LTTNG_TESTPOINT_ENABLE=1 \ + NOTIFIER_PAUSE_PIPE_PATH=${TESTPOINT_PIPE_PATH} \ + LD_PRELOAD=${TESTPOINT}" + + diag "Kernel event notifer error counter" + + start_lttng_sessiond_notap + + # This is needed since the testpoint creates a pipe with the sessiond + # type suffixed. + for f in "$TESTPOINT_BASE_PATH"*; do + sessiond_pipe+=("$f") + done + + lttng_add_trigger_ok "$trigger_name" \ + --condition on-event --kernel lttng_test_filter_event \ + --action notify + + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + + # Confirm that the discarded notification line is present. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + ok $? "No discarded tracer notification" + + # Stop consumption of notifier tracer notifications. + echo -n 1 > $sessiond_pipe + + # The notifier ring buffer configuration is currently made of 16 4096 + # bytes subbuffers. Each kernel notification is at least 42 bytes long. + # To fill it, we need to generate (16 * 4096)/42 = 1561 notifications. + # That number is a bit larger than what we need since some of the space + # is lost in subbuffer boundaries. + echo -n "200000" > /proc/lttng-test-filter-event + + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + + # Confirm that the discarded notification line is present. To avoid + # false positives. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded" + ok $? "Tracer notification discarded line printed" + + # Confirm that the number of tracer notifications discarded is not zero. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + isnt $? 0 "Discarded tracer notification number non-zero as expected" + + lttng_remove_trigger_ok "$trigger_name" + + # Confirm that no notifier is enabled. + list_triggers_line_count=$("$FULL_LTTNG_BIN" list-triggers | wc -l) + is "$list_triggers_line_count" "0" "No \`on-event\` kernel notifier enabled as expected" + + # Enable another notifier and list it to confirm the counter was cleared. + lttng_add_trigger_ok "$trigger_name" \ + --condition on-event --kernel lttng_test_filter_event \ + --action notify + + # Confirm that the discarded notification line is present. + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + ok $? "No discarded tracer notification" + + lttng_remove_trigger_ok "$trigger_name" + + stop_lttng_sessiond_notap + + unset LTTNG_SESSIOND_ENV_VARS + + rm -f "$list_triggers_stdout" +} + +function test_kernel_notifier_discarded_count_max_bucket +{ + start_lttng_sessiond "" "--event-notifier-error-number-of-bucket=3" + + diag "Kernel event notifer error counter bucket limit" + for i in $(seq 3); do + lttng_add_trigger_ok "$i" \ + --condition on-event --kernel my_event_that_doesnt_need_to_really_exist_$i \ + --action notify + done + + for i in $(seq 4 5); do + lttng_add_trigger_fail "$i" \ + --condition on-event --kernel my_event_that_doesnt_need_to_really_exist_$i \ + --action notify + done + + stop_lttng_sessiond_notap +} + +function test_ust_notifier_discarded_count +{ + local sessiond_pipe=() + local trigger_name="my_trigger" + local list_triggers_stdout=$(mktemp -t list_triggers_stdout.XXXXXX) + local NR_USEC_WAIT=0 + local PIPE_SIZE + local NR_ITER + + diag "UST event notifer error counter" + + PIPE_SIZE=$("$CURDIR"/default_pipe_size_getter) + if [ $? -ne 0 ]; then + BAIL_OUT "Failed to get system default pipe size" + else + diag "Default system pipe size: $PIPE_SIZE bytes" + fi + + # Find the number of events needed to overflow the event notification + # pipe buffer. Each LTTng-UST notification is at least 42 bytes long. + # Double that number to ensure enough events are created to overflow + # the buffer. + NR_ITER=$(( (PIPE_SIZE / 42) * 2 )) + diag "Test application will emit $NR_ITER events" + + # Used on sessiond launch. + LTTNG_SESSIOND_ENV_VARS="LTTNG_TESTPOINT_ENABLE=1 \ + NOTIFIER_PAUSE_PIPE_PATH=${TESTPOINT_PIPE_PATH} \ + LD_PRELOAD=${TESTPOINT}" + + start_lttng_sessiond_notap + + # This is needed since the testpoint create a pipe with the sessiond + # type suffixed. + for f in "$TESTPOINT_BASE_PATH"*; do + sessiond_pipe+=("$f") + done + + lttng_add_trigger_ok "$trigger_name" \ + --condition on-event --userspace tp:tptest \ + --action notify + + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + + # Confirm that the discarded notification line is present. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + ok $? "No discarded tracer notification" + + # Stop consumption of notifier tracer notifications. + echo -n 1 > $sessiond_pipe + + $TESTAPP_BIN -i $NR_ITER -w $NR_USEC_WAIT + ok $? "Generating $NR_ITER tracer notifications" + + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + + # Confirm that the discarded notification line is present. To avoid + # false positive. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded" + ok $? "Tracer notification discarded line printed" + + # Confirm that the number of tracer notifications discarded is not zero. + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + isnt $? 0 "Discarded tracer notification number non-zero as expected" + + # Remove the notifier. + lttng_remove_trigger_ok "$trigger_name" + + # Confirm that no notifier is enabled. + list_triggers_line_count=$("$FULL_LTTNG_BIN" list-triggers | wc -l) + is "$list_triggers_line_count" "0" "No \`on-event\` userspace notifier enabled as expected" + + # Enable another notifier and list it to confirm the counter was cleared. + lttng_add_trigger_ok "$trigger_name" \ + --condition on-event --userspace tp:tptest \ + --action notify + + # Confirm that the discarded notification line is present. + "$FULL_LTTNG_BIN" list-triggers > "$list_triggers_stdout" + cat "$list_triggers_stdout" | grep --quiet "tracer notifications discarded: 0" + ok $? "No discarded tracer notification" + + lttng_remove_trigger_ok "$trigger_name" + + stop_lttng_sessiond_notap + + unset LTTNG_SESSIOND_ENV_VARS + + rm -f "$list_triggers_stdout" +} +function test_ust_notifier_discarded_count_max_bucket +{ + start_lttng_sessiond "" "--event-notifier-error-number-of-bucket=3" + + diag "UST event notifer error counter bucket limit" + for i in $(seq 3); do + lttng_add_trigger_ok "$i" \ + --condition on-event --userspace my_event_that_doesnt_need_to_really_exist_$i \ + --action notify + done + + for i in $(seq 4 5); do + lttng_add_trigger_fail "$i" \ + --condition on-event --userspace my_event_that_doesnt_need_to_really_exist_$i \ + --action notify + done + + stop_lttng_sessiond_notap +} + +test_ust_notifier_discarded_count +test_ust_notifier_discarded_count_max_bucket + +if [ "$(id -u)" == "0" ]; then + + validate_lttng_modules_present + + modprobe lttng-test + + test_kernel_notifier_discarded_count + + test_kernel_notifier_discarded_count_max_bucket + + modprobe --remove lttng-test + + rm -rf "${sessiond_pipe[@]}" 2> /dev/null +else + # Kernel tests are skipped. + skip 0 "Root access is needed. Skipping all kernel notification tests." $KERNEL_NUM_TESTS +fi + +rm -rf "$TMPDIR" diff --git a/tests/utils/utils.sh b/tests/utils/utils.sh index 15d7e8b56..4ef4c7264 100644 --- a/tests/utils/utils.sh +++ b/tests/utils/utils.sh @@ -2166,6 +2166,11 @@ function lttng_add_trigger_ok() lttng_add_trigger 0 "$@" } +function lttng_add_trigger_fail() +{ + lttng_add_trigger 1 "$@" +} + function lttng_remove_trigger_ok() { lttng_remove_trigger 0 "$@" -- 2.34.1