From: Michael Jeanson Date: Fri, 11 Feb 2022 15:26:02 +0000 (+0000) Subject: Add Log4j 2.x agent tests for the 'log4j' domain X-Git-Tag: v2.13.5~11 X-Git-Url: https://git.lttng.org./?a=commitdiff_plain;h=7f6639c208fdea0b21476c24577d4286bf2aa80a;p=lttng-tools.git Add Log4j 2.x agent tests for the 'log4j' domain Add integration tests for the new Log4j 2.x agent in Log4j 1.x compat mode using the current 'log4j' domain, use the new configure switch '--enable-test-java-agent-log4j2' to enable it. To run only this new test, use this command : cd tests/regression && make check TESTS="ust/java-log4j2/test_agent_log4j2_domain_log4j" Change-Id: Id780c9ee13913c91c18548f58b14cc600e77e9fa Depends-on: lttng-ust: I7fd5f79ad58c77175714bd4198d8ff5db2e6b846 Signed-off-by: Michael Jeanson Signed-off-by: Jérémie Galarneau --- diff --git a/configure.ac b/configure.ac index 9c43dccd7..54768f155 100644 --- a/configure.ac +++ b/configure.ac @@ -338,11 +338,17 @@ AC_ARG_ENABLE([test-java-agent-jul], ) AC_ARG_ENABLE([test-java-agent-log4j], - [AS_HELP_STRING([--enable-test-java-agent-log4j],[enable the LTTng UST Java agent Log4j tests [default=no]])], + [AS_HELP_STRING([--enable-test-java-agent-log4j],[enable the LTTng UST Java agent Log4j 1.x tests [default=no]])], [test_java_agent_log4j=$enableval], [test_java_agent_log4j=no] ) +AC_ARG_ENABLE([test-java-agent-log4j2], + [AS_HELP_STRING([--enable-test-java-agent-log4j2],[enable the LTTng UST Java agent Log4j 2.x tests [default=no]])], + [test_java_agent_log4j2=$enableval], + [test_java_agent_log4j2=no] +) + AC_ARG_ENABLE([test-java-agent-all], [AS_HELP_STRING([--enable-test-java-agent-all],[enable all the LTTng UST Java agent tests [default=no]])], [test_java_agent_jul=$enableval @@ -615,8 +621,9 @@ AX_CONFIG_FEATURE( AM_CONDITIONAL([TEST_JAVA_JUL_AGENT], [test "x$test_java_agent_jul" = "xyes"]) AM_CONDITIONAL([TEST_JAVA_LOG4J_AGENT], [test "x$test_java_agent_log4j" = "xyes"]) +AM_CONDITIONAL([TEST_JAVA_LOG4J2_AGENT], [test "x$test_java_agent_log4j2" = "xyes"]) -if test "x$test_java_agent_jul" = "xyes" || test "x$test_java_agent_log4j" = "xyes"; then +if test "x$test_java_agent_jul" = "xyes" || test "x$test_java_agent_log4j" = "xyes" || test "x$test_java_agent_log4j2" = "xyes"; then AX_JAVA_OPTIONS AX_PROG_JAVAC AX_PROG_JAVA @@ -651,6 +658,21 @@ if test "x$test_java_agent_jul" = "xyes" || test "x$test_java_agent_log4j" = "xy AC_MSG_ERROR([The Log4j class was not found. Please specify the location of the jar via the Java CLASSPATH e.g: export CLASSPATH="/path/to/log4j.jar"]) fi fi + + if test "x$test_java_agent_log4j2" = "xyes"; then + # Check for Log4j2 agent class + AX_CHECK_CLASS(org.lttng.ust.agent.log4j2.LttngLogAppender) + if test "x$ac_cv_class_org_lttng_ust_agent_log4j2_LttngLogAppender" = "xno"; then + AC_MSG_ERROR([The UST Java agent Log4j 2.x class was not found. Please specify the location of the jar via the Java CLASSPATH e.g: export CLASSPATH="/path/to/lttng-ust-agent-log4j2.jar"]) + fi + + # Check for Log4j 2.x classes + AX_CHECK_CLASS([org.apache.logging.log4j.Logger]) + AX_CHECK_CLASS([org.apache.logging.log4j.core.Core]) + if test "x$ac_cv_class_org_apache_logging_log4j_Logger" = "xno" || test "x$ac_cv_class_org_apache_logging_log4j_core_Core" = "xno"; then + AC_MSG_ERROR([The Log4j 2.x API or core class was not found. Please specify the location of the jars via the Java CLASSPATH e.g: export CLASSPATH="/path/to/log4j-core.jar:/path/to/log4j-api.jar"]) + fi + fi fi # enable building man pages (user's intention) @@ -1173,6 +1195,7 @@ AC_CONFIG_FILES([ tests/regression/ust/ust-dl/Makefile tests/regression/ust/java-jul/Makefile tests/regression/ust/java-log4j/Makefile + tests/regression/ust/java-log4j2/Makefile tests/regression/ust/getcpu-override/Makefile tests/regression/ust/clock-override/Makefile tests/regression/ust/type-declarations/Makefile @@ -1290,9 +1313,13 @@ AS_IF([test "x$build_tests" = "xno"],[ test "x$test_java_agent_jul" = "xyes" && value=1 || value=0 PPRINT_PROP_BOOL([LTTng-UST Java agent JUL tests], $value) -# LTTng UST Java agent Log4j tests enabled/disabled +# LTTng UST Java agent Log4j 1.x tests enabled/disabled test "x$test_java_agent_log4j" = "xyes" && value=1 || value=0 -PPRINT_PROP_BOOL([LTTng-UST Java agent Log4j tests], $value) +PPRINT_PROP_BOOL([LTTng-UST Java agent Log4j 1.x tests], $value) + +# LTTng UST Java agent Log4j 2.x tests enabled/disabled +test "x$test_java_agent_log4j2" = "xyes" && value=1 || value=0 +PPRINT_PROP_BOOL([LTTng-UST Java agent Log4j 2.x tests], $value) test ! -z "$PYTHON2_AGENT" && value=1 || value=0 PPRINT_PROP_BOOL([LTTng-UST Python2 agent tests], $value) diff --git a/tests/regression/Makefile.am b/tests/regression/Makefile.am index 74a4c48f1..7ac7e0974 100644 --- a/tests/regression/Makefile.am +++ b/tests/regression/Makefile.am @@ -64,8 +64,6 @@ TESTS += ust/before-after/test_before_after \ ust/multi-session/test_multi_session \ ust/nprocesses/test_nprocesses \ ust/overlap/test_overlap \ - ust/java-jul/test_java_jul \ - ust/java-log4j/test_java_log4j \ ust/python-logging/test_python_logging \ ust/getcpu-override/test_getcpu_override \ ust/clock-override/test_clock_override \ @@ -79,6 +77,18 @@ TESTS += ust/before-after/test_before_after \ tools/relayd-grouping/test_ust \ tools/trigger/rate-policy/test_ust_rate_policy +if TEST_JAVA_JUL_AGENT +TESTS += ust/java-jul/test_java_jul +endif # TEST_JAVA_JUL_AGENT + +if TEST_JAVA_LOG4J_AGENT +TESTS += ust/java-log4j/test_java_log4j +endif # TEST_JAVA_LOG4J_AGENT + +if TEST_JAVA_LOG4J2_AGENT +TESTS += ust/java-log4j2/test_agent_log4j2_domain_log4j +endif # TEST_JAVA_LOG4J2_AGENT + if IS_LINUX TESTS += \ kernel/test_all_events \ diff --git a/tests/regression/ust/Makefile.am b/tests/regression/ust/Makefile.am index 49a1811ff..5af414966 100644 --- a/tests/regression/ust/Makefile.am +++ b/tests/regression/ust/Makefile.am @@ -13,6 +13,7 @@ SUBDIRS = \ high-throughput \ java-jul \ java-log4j \ + java-log4j2 \ libc-wrapper \ linking \ low-throughput \ diff --git a/tests/regression/ust/java-log4j/JTestLTTng.java b/tests/regression/ust/java-log4j/JTestLTTng.java deleted file mode 100644 index 1b4a51b45..000000000 --- a/tests/regression/ust/java-log4j/JTestLTTng.java +++ /dev/null @@ -1,88 +0,0 @@ -/* - * Copyright (C) 2015 Michael Jeanson - * Copyright (C) 2014 David Goulet - * Copyright (C) 2014 Christian Babeux - * - * SPDX-License-Identifier: GPL-2.0-only - * - */ - -import java.io.IOException; -import java.lang.Integer; - -import org.apache.log4j.Appender; -import org.apache.log4j.BasicConfigurator; -import org.apache.log4j.Logger; -import org.apache.log4j.Level; -import org.lttng.ust.agent.log4j.LttngLogAppender; - -public class JTestLTTng { - - /** - * Application start - * - * @param args - * Command-line arguments - * @throws IOException - * @throws InterruptedException - */ - public static void main(String args[]) throws IOException, InterruptedException { - - Logger lttng = Logger.getLogger("log4j-event"); - Logger lttng2 = Logger.getLogger("log4j-event-2"); - - /* - * Set lowest level to make sure all event levels are logged. - * Any jar can override the default log4j rootLogger level - * and a logger with no explicit level defaults to the non-null - * parent level. Events could be ignored if the inherited value - * is too low, thereby failing the test. - * - * See BSF -> https://issues.apache.org/jira/browse/BSF-24 - */ - lttng.setLevel(Level.ALL); - lttng2.setLevel(Level.ALL); - - int nrIter = Integer.parseInt(args[0]); - int waitTime = Integer.parseInt(args[1]); - int fire_debug_tp = 0; - int fire_second_tp = 0; - - if (args.length > 2) { - fire_debug_tp = Integer.parseInt(args[2]); - } - if (args.length > 3) { - fire_second_tp = Integer.parseInt(args[3]); - } - - /* Start with the default Log4j configuration, which logs to console */ - BasicConfigurator.configure(); - - /* - * Add a LTTng log appender to both loggers, which will also send the - * logged events to UST. - */ - Appender lttngAppender = new LttngLogAppender(); - lttng.addAppender(lttngAppender); - lttng2.addAppender(lttngAppender); - - for (int iter = 0; iter < nrIter; iter++) { - lttng.info("LOG4J tp fired!"); - if (fire_debug_tp == 1) { - /* Third arg, trigger debug TP. */ - lttng.debug("LOG4J DEBUG tp fired"); - } - Thread.sleep(waitTime); - } - - if (fire_second_tp == 1) { - lttng2.info("LOG4J second logger fired"); - } - - /* - * Do not forget to close() all handlers so that the agent can shutdown - * and the session daemon socket gets cleaned up explicitly. - */ - lttngAppender.close(); - } -} diff --git a/tests/regression/ust/java-log4j/JTestLTTngLog4j.java b/tests/regression/ust/java-log4j/JTestLTTngLog4j.java new file mode 100644 index 000000000..3742836c8 --- /dev/null +++ b/tests/regression/ust/java-log4j/JTestLTTngLog4j.java @@ -0,0 +1,88 @@ +/* + * Copyright (C) 2015 Michael Jeanson + * Copyright (C) 2014 David Goulet + * Copyright (C) 2014 Christian Babeux + * + * SPDX-License-Identifier: GPL-2.0-only + * + */ + +import java.io.IOException; +import java.lang.Integer; + +import org.apache.log4j.Appender; +import org.apache.log4j.BasicConfigurator; +import org.apache.log4j.Logger; +import org.apache.log4j.Level; +import org.lttng.ust.agent.log4j.LttngLogAppender; + +public class JTestLTTngLog4j { + + /** + * Application start + * + * @param args + * Command-line arguments + * @throws IOException + * @throws InterruptedException + */ + public static void main(String args[]) throws IOException, InterruptedException { + + Logger lttng = Logger.getLogger("log4j-event"); + Logger lttng2 = Logger.getLogger("log4j-event-2"); + + /* + * Set lowest level to make sure all event levels are logged. + * Any jar can override the default log4j rootLogger level + * and a logger with no explicit level defaults to the non-null + * parent level. Events could be ignored if the inherited value + * is too low, thereby failing the test. + * + * See BSF -> https://issues.apache.org/jira/browse/BSF-24 + */ + lttng.setLevel(Level.ALL); + lttng2.setLevel(Level.ALL); + + int nrIter = Integer.parseInt(args[0]); + int waitTime = Integer.parseInt(args[1]); + int fire_debug_tp = 0; + int fire_second_tp = 0; + + if (args.length > 2) { + fire_debug_tp = Integer.parseInt(args[2]); + } + if (args.length > 3) { + fire_second_tp = Integer.parseInt(args[3]); + } + + /* Start with the default Log4j configuration, which logs to console */ + BasicConfigurator.configure(); + + /* + * Add a LTTng log appender to both loggers, which will also send the + * logged events to UST. + */ + Appender lttngAppender = new LttngLogAppender(); + lttng.addAppender(lttngAppender); + lttng2.addAppender(lttngAppender); + + for (int iter = 0; iter < nrIter; iter++) { + lttng.info("LOG4J tp fired!"); + if (fire_debug_tp == 1) { + /* Third arg, trigger debug TP. */ + lttng.debug("LOG4J DEBUG tp fired"); + } + Thread.sleep(waitTime); + } + + if (fire_second_tp == 1) { + lttng2.info("LOG4J second logger fired"); + } + + /* + * Do not forget to close() all handlers so that the agent can shutdown + * and the session daemon socket gets cleaned up explicitly. + */ + lttngAppender.close(); + } +} diff --git a/tests/regression/ust/java-log4j/Makefile.am b/tests/regression/ust/java-log4j/Makefile.am index be50eaf98..63e604c5e 100644 --- a/tests/regression/ust/java-log4j/Makefile.am +++ b/tests/regression/ust/java-log4j/Makefile.am @@ -2,11 +2,11 @@ JAVAROOT = . -noinst_SCRIPTS = test_java_log4j JTestLTTng.java -EXTRA_DIST = test_java_log4j JTestLTTng.java +noinst_SCRIPTS = test_java_log4j JTestLTTngLog4j.java +EXTRA_DIST = test_java_log4j JTestLTTngLog4j.java if TEST_JAVA_LOG4J_AGENT -dist_noinst_JAVA = JTestLTTng.java +dist_noinst_JAVA = JTestLTTngLog4j.java endif # TEST_JAVA_LOG4J_AGENT all-local: static_file diff --git a/tests/regression/ust/java-log4j/test_java_log4j b/tests/regression/ust/java-log4j/test_java_log4j index fc16e02d0..825889f52 100755 --- a/tests/regression/ust/java-log4j/test_java_log4j +++ b/tests/regression/ust/java-log4j/test_java_log4j @@ -6,85 +6,62 @@ TEST_DESC="Java LOG4J support" -CURDIR=$(dirname $0)/ +CURDIR=$(dirname "$0")/ TESTDIR=$CURDIR/../../.. + NR_ITER=6 -NR_MSEC_WAIT=1000 -TESTAPP_NAME="JTestLTTng" -TESTAPP_BIN="$TESTAPP_NAME.java" +NR_MSEC_WAIT=100 + +TESTAPP_NAME="JTestLTTngLog4j" TESTAPP_PATH="$CURDIR/$TESTAPP_NAME" + SESSION_NAME="log4j" EVENT_NAME="log4j-event" EVENT_NAME2="log4j-event-2" + JAVA_CP="$CURDIR:$CLASSPATH" -OUTPUT_DEST="/dev/null" -NUM_TESTS=195 +NUM_TESTS=196 -source $TESTDIR/utils/utils.sh +# shellcheck source=../../../utils/utils.sh +source "$TESTDIR/utils/utils.sh" function run_app { local debug_tp=$1 local fire_second_tp=$2 - # FIXME: test app should have synchro. - java -cp $JAVA_CP -Djava.library.path="$LD_LIBRARY_PATH:/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $debug_tp $fire_second_tp >/dev/null 2>&1 -} - -function run_app_background -{ - run_app $@ & -} + if [ "$debug_tp" = "" ]; then + debug_tp=0 + fi -function enable_log4j_loglevel_only() -{ - sess_name=$1 - event_name="$2" - loglevel=$3 - channel_name=$4 - - if [ -z $channel_name ]; then - # default channel if none specified - chan="" - else - chan="-c $channel_name" + if [ "$fire_second_tp" = "" ]; then + fire_second_tp=0 fi - $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event --loglevel-only $loglevel "$event_name" $chan -s $sess_name -l >/dev/null 2>&1 - ok $? "Enable LOG4J event $event_name for session $sess_name with loglevel-only $loglevel" + # FIXME: test app should have synchro. + diag "java -cp $JAVA_CP -Djava.library.path=\"$LD_LIBRARY_PATH:/usr/local/lib:/usr/lib\" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $debug_tp $fire_second_tp" + java -cp "$JAVA_CP" -Djava.library.path="$LD_LIBRARY_PATH:/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT "$debug_tp" "$fire_second_tp" >"$OUTPUT_DEST" 2>"$ERROR_OUTPUT_DEST" } -function enable_log4j_filter() +function run_app_background { - local sess_name="$1" - local event_name="$2" - local filter="$3" - - $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "$event_name" -s $sess_name -l --filter "$filter" >/dev/null 2>&1 - ok $? "Enable event $event_name with filter $filter for session $sess_name" + run_app "${@}" & } -function enable_log4j_filter_loglevel_only() -{ - local sess_name="$1" - local event_name="$2" - local filter="$3" - local loglevel="$4" - - $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event --loglevel-only $loglevel "$event_name" -s $sess_name -l --filter "$filter" >/dev/null 2>&1 - ok $? "Enable event $event_name with filter \"$filter\" and loglevel-only $loglevel for session $sess_name" -} # MUST set TESTDIR before calling those functions function test_log4j_before_start () { - local file_sync_after_first=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_after_first.XXXXXX") - local file_sync_before_last=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX") + local file_sync_after_first + local file_sync_before_last + + file_sync_after_first=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_after_first.XXXXXX") + file_sync_before_last=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX") diag "Test LOG4J application BEFORE tracing starts" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME # Run 5 times with a 1 second delay @@ -92,7 +69,7 @@ function test_log4j_before_start () start_lttng_tracing_ok $SESSION_NAME - touch ${file_sync_before_last} + touch "${file_sync_before_last}" # Wait for the applications started in background wait @@ -100,21 +77,18 @@ function test_log4j_before_start () stop_lttng_tracing_ok $SESSION_NAME destroy_lttng_session_ok $SESSION_NAME - rm -f ${file_sync_after_first} - rm -f ${file_sync_before_last} + rm -f "${file_sync_after_first}" + rm -f "${file_sync_before_last}" # Validate test. Expecting all events. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH" } function test_log4j_after_start () { diag "Test LOG4J application AFTER tracing starts" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing_ok $SESSION_NAME @@ -125,17 +99,14 @@ function test_log4j_after_start () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting all events. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH" } function test_log4j_loglevel () { diag "Test LOG4J application with loglevel" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO" start_lttng_tracing_ok $SESSION_NAME @@ -146,14 +117,11 @@ function test_log4j_loglevel () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting all events. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH" diag "Test LOG4J applications with lower loglevel" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_FATAL" start_lttng_tracing_ok $SESSION_NAME @@ -164,14 +132,11 @@ function test_log4j_loglevel () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting 0 events. - trace_match_only $EVENT_NAME 0 $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH" diag "Test LOG4J applications with higher loglevel" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_TRACE" start_lttng_tracing_ok $SESSION_NAME @@ -182,15 +147,14 @@ function test_log4j_loglevel () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting all events. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH - return $? + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH" } function test_log4j_loglevel_multiple () { diag "Test LOG4J application with multiple loglevel" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO" enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_DEBUG" start_lttng_tracing_ok $SESSION_NAME @@ -202,12 +166,9 @@ function test_log4j_loglevel_multiple () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting all events times two. - trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $((NR_ITER * 2)) "$TRACE_PATH" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH" enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_INFO" enable_log4j_lttng_event_loglevel $SESSION_NAME '*' "LOG4J_DEBUG" start_lttng_tracing_ok $SESSION_NAME @@ -219,22 +180,19 @@ function test_log4j_loglevel_multiple () destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting all events times two. - trace_match_only $EVENT_NAME $(($NR_ITER * 2)) $TRACE_PATH - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $((NR_ITER * 2)) "$TRACE_PATH" } function test_log4j_multi_session_loglevel() { diag "Test LOG4J with multiple session" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 - enable_log4j_loglevel_only $SESSION_NAME-1 '*' "LOG4J_INFO" + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 + enable_log4j_lttng_event_loglevel_only $SESSION_NAME-1 '*' "LOG4J_INFO" start_lttng_tracing_ok $SESSION_NAME-1 - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 - enable_log4j_loglevel_only $SESSION_NAME-2 '*' "LOG4J_DEBUG" + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 + enable_log4j_lttng_event_loglevel_only $SESSION_NAME-2 '*' "LOG4J_DEBUG" start_lttng_tracing_ok $SESSION_NAME-2 # Run 5 times with a 1 second delay and fire second TP. @@ -246,29 +204,23 @@ function test_log4j_multi_session_loglevel() destroy_lttng_session_ok $SESSION_NAME-2 # Expecting 6 events being the main event plus the second tp. - trace_match_only $EVENT_NAME $(($NR_ITER + 1)) $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $((NR_ITER + 1)) "$TRACE_PATH"/$SESSION_NAME-1 # Expectin 5 events being the debug TP. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_multi_session_disable() { diag "Test LOG4J with multiple session with disabled event" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME2 disable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME start_lttng_tracing_ok $SESSION_NAME-1 - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2 start_lttng_tracing_ok $SESSION_NAME-2 @@ -281,26 +233,20 @@ function test_log4j_multi_session_disable() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting one event of the second TP. - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting one event of the second TP. - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_multi_session_disable_wildcard() { diag "Test LOG4J with multiple session with disabled wildcard event" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 '*' - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 '*' disable_log4j_lttng_event $SESSION_NAME-1 '*' @@ -316,16 +262,10 @@ function test_log4j_multi_session_disable_wildcard() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting NO event of the first TP. - trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting all events of the first TP. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_multi_session_disable_wildcard_begin() @@ -333,10 +273,10 @@ function test_log4j_multi_session_disable_wildcard_begin() ev_name='*-event' diag "Test LOG4J with multiple session with disabled wildcard (at the beginning) event" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 "$ev_name" disable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" @@ -352,16 +292,10 @@ function test_log4j_multi_session_disable_wildcard_begin() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting NO event of the first TP. - trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting all events of the first TP. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_multi_session_disable_wildcard_middle() @@ -369,10 +303,10 @@ function test_log4j_multi_session_disable_wildcard_middle() ev_name='log*nt' diag "Test LOG4J with multiple session with disabled wildcard (at the middle) event" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 "$ev_name" disable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" @@ -388,16 +322,10 @@ function test_log4j_multi_session_disable_wildcard_middle() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting NO event of the first TP. - trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting all events of the first TP. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_multi_session_disable_wildcard_end() @@ -405,10 +333,10 @@ function test_log4j_multi_session_disable_wildcard_end() ev_name='log4j-ev*' diag "Test LOG4J with multiple session with disabled wildcard (at the end) event" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 "$ev_name" disable_log4j_lttng_event $SESSION_NAME-1 "$ev_name" @@ -424,28 +352,19 @@ function test_log4j_multi_session_disable_wildcard_end() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting NO event of the first TP. - trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting all events of the first TP. - trace_matches $EVENT_NAME $(( $NR_ITER + 1 )) $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_matches $EVENT_NAME $(( NR_ITER + 1 )) "$TRACE_PATH"/$SESSION_NAME-2 - trace_matches $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_matches $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_disable_all() { diag "Test LOG4J with multiple session with disabled all event" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME enable_log4j_lttng_event $SESSION_NAME '*' enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2 @@ -460,22 +379,19 @@ function test_log4j_disable_all() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting NO event of the first TP and second TP. - trace_match_only $EVENT_NAME 0 $TRACE_PATH/$SESSION_NAME - trace_match_only $EVENT_NAME2 0 $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME 0 "$TRACE_PATH"/$SESSION_NAME + trace_match_only $EVENT_NAME2 0 "$TRACE_PATH"/$SESSION_NAME } function test_log4j_multi_session() { diag "Test LOG4J with multiple session" - create_lttng_session_ok $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + create_lttng_session_ok $SESSION_NAME-1 "$TRACE_PATH"/$SESSION_NAME-1 enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME start_lttng_tracing_ok $SESSION_NAME-1 - create_lttng_session_ok $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + create_lttng_session_ok $SESSION_NAME-2 "$TRACE_PATH"/$SESSION_NAME-2 enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2 start_lttng_tracing_ok $SESSION_NAME-2 @@ -488,23 +404,17 @@ function test_log4j_multi_session() destroy_lttng_session_ok $SESSION_NAME-2 # Validate test. Expecting all events of first TP - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME-1 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME-1 # Validate test. Expecting one event of the second TP. - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME-2 - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME-2 } function test_log4j_destroy_session() { diag "Test LOG4J two session with destroy" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/first-sess + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/first-sess enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing_ok $SESSION_NAME @@ -517,12 +427,9 @@ function test_log4j_destroy_session() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting at least one event num 1 - validate_trace $EVENT_NAME $TRACE_PATH/first-sess - if [ $? -ne 0 ]; then - return $? - fi + validate_trace $EVENT_NAME "$TRACE_PATH"/first-sess - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/second-sess + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/second-sess enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2 start_lttng_tracing_ok $SESSION_NAME @@ -535,19 +442,16 @@ function test_log4j_destroy_session() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting only one event num 2 - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/second-sess - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/second-sess } function test_log4j_filtering() { diag "Test LOG4J filtering" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME # Enable all event with a filter. - enable_log4j_filter $SESSION_NAME '*' 'msg == "LOG4J second logger fired"' + enable_log4j_lttng_event_filter $SESSION_NAME '*' 'msg == "LOG4J second logger fired"' start_lttng_tracing_ok $SESSION_NAME # Run 5 times with a 1 second delay and fire second TP. @@ -557,15 +461,12 @@ function test_log4j_filtering() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting one event of the second TP only. - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME # Enable first Logger but filter msg payload for the INFO one while # triggering the debug and second TP. - enable_log4j_filter $SESSION_NAME $EVENT_NAME 'msg == "LOG4J tp fired!"' + enable_log4j_lttng_event_filter $SESSION_NAME $EVENT_NAME 'msg == "LOG4J tp fired!"' start_lttng_tracing_ok $SESSION_NAME # Run 5 times with a 1 second delay, fire debug and second TP. @@ -575,17 +476,14 @@ function test_log4j_filtering() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting NR_ITER event of the main INFO tp. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME } function test_log4j_disable() { diag "Test LOG4J disable event" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME # Enable all event with a filter. enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2 @@ -599,17 +497,14 @@ function test_log4j_disable() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting one event of the second TP only. - trace_match_only $EVENT_NAME2 1 $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH"/$SESSION_NAME } function test_log4j_disable_enable() { diag "Test LOG4J disable event followed by an enable" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME # Enable all event with a filter. enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME @@ -623,10 +518,7 @@ function test_log4j_disable_enable() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting NR_ITER event of the main INFO tp. - trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $EVENT_NAME $NR_ITER "$TRACE_PATH"/$SESSION_NAME } function test_log4j_filter_loglevel() @@ -637,11 +529,11 @@ function test_log4j_filter_loglevel() diag "Test LOG4J a filter with a loglevel" - create_lttng_session_ok $SESSION_NAME $TRACE_PATH/$SESSION_NAME + create_lttng_session_ok $SESSION_NAME "$TRACE_PATH"/$SESSION_NAME # Enable an event with a filter and the loglevel-only option. - enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO + enable_log4j_lttng_event_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO disable_log4j_lttng_event $SESSION_NAME $BOGUS_EVENT_NAME - enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO + enable_log4j_lttng_event_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO start_lttng_tracing_ok $SESSION_NAME # Run 5 times with a 1 second delay and fire second TP. @@ -651,56 +543,47 @@ function test_log4j_filter_loglevel() destroy_lttng_session_ok $SESSION_NAME # Validate test. Expecting no events. - trace_match_only $ALL_EVENTS 0 $TRACE_PATH/$SESSION_NAME - if [ $? -ne 0 ]; then - return $? - fi + trace_match_only $ALL_EVENTS 0 "$TRACE_PATH"/$SESSION_NAME } plan_tests $NUM_TESTS print_test_banner "$TEST_DESC" -if [ ! -f "$TESTAPP_PATH.class" ]; then - withapp=0 -else - withapp=1 -fi - -skip $withapp "LOG4J support is needed. Skipping all tests." $NUM_TESTS || -{ - start_lttng_sessiond - - tests=( - test_log4j_multi_session_disable_wildcard - test_log4j_multi_session_disable_wildcard_begin - test_log4j_multi_session_disable_wildcard_middle - test_log4j_multi_session_disable_wildcard_end - test_log4j_multi_session_disable - test_log4j_disable - test_log4j_disable_enable - test_log4j_disable_all - test_log4j_filtering - test_log4j_multi_session_loglevel - test_log4j_destroy_session - test_log4j_loglevel - test_log4j_loglevel_multiple - test_log4j_before_start - test_log4j_after_start - test_log4j_multi_session - test_log4j_filter_loglevel - ) - - for fct_test in ${tests[@]}; - do - TRACE_PATH=$(mktemp --tmpdir -d tmp.test_java_log4j_trace_path.XXXXXX) - - ${fct_test} - if [ $? -ne 0 ]; then - break; - fi - rm -rf $TRACE_PATH - done - - stop_lttng_sessiond -} +bail_out_if_no_babeltrace + +test -f "$TESTAPP_PATH.class" +ok $? "Testapp '$TESTAPP_NAME' present" + +start_lttng_sessiond + +tests=( + test_log4j_multi_session_disable_wildcard + test_log4j_multi_session_disable_wildcard_begin + test_log4j_multi_session_disable_wildcard_middle + test_log4j_multi_session_disable_wildcard_end + test_log4j_multi_session_disable + test_log4j_disable + test_log4j_disable_enable + test_log4j_disable_all + test_log4j_filtering + test_log4j_multi_session_loglevel + test_log4j_destroy_session + test_log4j_loglevel + test_log4j_loglevel_multiple + test_log4j_before_start + test_log4j_after_start + test_log4j_multi_session + test_log4j_filter_loglevel +) + +for fct_test in "${tests[@]}"; +do + TRACE_PATH=$(mktemp --tmpdir -d tmp.test_java_log4j_trace_path.XXXXXX) + + ${fct_test} + + rm -rf "$TRACE_PATH" +done + +stop_lttng_sessiond diff --git a/tests/regression/ust/java-log4j2/JTestLTTngLog4j2.java b/tests/regression/ust/java-log4j2/JTestLTTngLog4j2.java new file mode 100644 index 000000000..6e9eb32df --- /dev/null +++ b/tests/regression/ust/java-log4j2/JTestLTTngLog4j2.java @@ -0,0 +1,59 @@ +/* + * Copyright (C) 2015 Michael Jeanson + * Copyright (C) 2014 David Goulet + * Copyright (C) 2014 Christian Babeux + * + * SPDX-License-Identifier: GPL-2.0-only + * + */ + +import java.io.IOException; +import java.lang.Integer; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.LogManager; + +public class JTestLTTngLog4j2 { + + /** + * Application start + * + * @param args + * Command-line arguments + * @throws IOException + * @throws InterruptedException + */ + public static void main(String args[]) throws IOException, InterruptedException { + + Logger console = LogManager.getLogger("console-event-1"); + Logger lttng = LogManager.getLogger("log4j2-event-1"); + Logger lttng2 = LogManager.getLogger("log4j2-event-2"); + + int nrIter = Integer.parseInt(args[0]); + int waitTime = Integer.parseInt(args[1]); /* milliseconds */ + int fire_debug_tp = 0; + int fire_second_tp = 0; + + if (args.length > 2) { + fire_debug_tp = Integer.parseInt(args[2]); + } + if (args.length > 3) { + fire_second_tp = Integer.parseInt(args[3]); + } + + console.info("CONSOLE only event."); + + for (int iter = 0; iter < nrIter; iter++) { + lttng.info("LOG4J2 INFO tp fired!"); + if (fire_debug_tp == 1) { + /* Third arg, trigger debug TP. */ + lttng.debug("LOG4J2 DEBUG tp fired"); + } + Thread.sleep(waitTime); + } + + if (fire_second_tp == 1) { + lttng2.info("LOG4J2 INFO second logger fired"); + } + } +} diff --git a/tests/regression/ust/java-log4j2/Makefile.am b/tests/regression/ust/java-log4j2/Makefile.am new file mode 100644 index 000000000..54892708d --- /dev/null +++ b/tests/regression/ust/java-log4j2/Makefile.am @@ -0,0 +1,32 @@ +# SPDX-License-Identifier: GPL-2.0-only + +JAVAROOT = . + +noinst_SCRIPTS = \ + test_agent_log4j2_domain_log4j + +EXTRA_DIST = \ + JTestLTTngLog4j2.java \ + domain-log4j.xml \ + test_agent_log4j2_domain_log4j + +if TEST_JAVA_LOG4J2_AGENT +dist_noinst_JAVA = JTestLTTngLog4j2.java +endif # TEST_JAVA_LOG4J2_AGENT + +all-local: static_file + +static_file: + @if [ x"$(srcdir)" != x"$(builddir)" ]; then \ + for script in $(EXTRA_DIST); do \ + cp -f $(srcdir)/$$script $(builddir); \ + done; \ + fi + +clean-local: + rm -f *.class + @if [ x"$(srcdir)" != x"$(builddir)" ]; then \ + for script in $(EXTRA_DIST); do \ + rm -f $(builddir)/$$script; \ + done; \ + fi diff --git a/tests/regression/ust/java-log4j2/domain-log4j.xml b/tests/regression/ust/java-log4j2/domain-log4j.xml new file mode 100644 index 000000000..be886b55f --- /dev/null +++ b/tests/regression/ust/java-log4j2/domain-log4j.xml @@ -0,0 +1,23 @@ + + + + + + + + + + + + + + + + + + + + + + + diff --git a/tests/regression/ust/java-log4j2/test_agent_log4j2_domain_log4j b/tests/regression/ust/java-log4j2/test_agent_log4j2_domain_log4j new file mode 100755 index 000000000..11091f545 --- /dev/null +++ b/tests/regression/ust/java-log4j2/test_agent_log4j2_domain_log4j @@ -0,0 +1,590 @@ +#!/bin/bash +# +# Copyright (C) 2014 David Goulet +# Copyright (C) 2022 EfficiOS Inc. +# +# SPDX-License-Identifier: GPL-2.0-only + +TEST_DESC="Java LOG4J 2.x Agent tests with 'log4j' domain" + +CURDIR=$(dirname "$0")/ +TESTDIR=$CURDIR/../../.. + +NR_ITER=6 +NR_MSEC_WAIT=100 + +TESTAPP_NAME="JTestLTTngLog4j2" +TESTAPP_PATH="$CURDIR/$TESTAPP_NAME" + +EVENT_NAME_BASE="log4j2-event" +EVENT_NAME1="$EVENT_NAME_BASE-1" +EVENT_NAME2="$EVENT_NAME_BASE-2" + +JAVA_CP="$CURDIR:$CLASSPATH" + +NUM_TESTS=196 + +# shellcheck source=../../../utils/utils.sh +source "$TESTDIR/utils/utils.sh" + +function run_app +{ + local debug_tp=$1 + local fire_second_tp=$2 + + if [ "$debug_tp" = "" ]; then + debug_tp=0 + fi + + if [ "$fire_second_tp" = "" ]; then + fire_second_tp=0 + fi + + # FIXME: test app should have synchro. + diag "java -cp $JAVA_CP -Dlog4j2.configurationFile=\"domain-log4j.xml\" -Djava.library.path=\"$LD_LIBRARY_PATH:/usr/local/lib:/usr/lib\" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $debug_tp $fire_second_tp" + java -cp "$JAVA_CP" -Dlog4j2.configurationFile="domain-log4j.xml" -Djava.library.path="$LD_LIBRARY_PATH:/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT "$debug_tp" "$fire_second_tp" >"$OUTPUT_DEST" 2>"$ERROR_OUTPUT_DEST" +} + +function run_app_background +{ + run_app "${@}" & +} + + +# MUST set TESTDIR before calling those functions + +function test_log4j2_before_start () +{ + local file_sync_after_first + local file_sync_before_last + + file_sync_after_first=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_after_first.XXXXXX") + file_sync_before_last=$(mktemp --tmpdir -u "tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX") + + diag "Test LOG4J2 application BEFORE tracing starts" + create_lttng_session_ok "log4j2_before_start" "$TRACE_PATH" + enable_log4j_lttng_event "log4j2_before_start" $EVENT_NAME1 + + # Run 6 times with a 100ms delay + run_app_background + + start_lttng_tracing_ok "log4j2_before_start" + + touch "${file_sync_before_last}" + + # Wait for the applications started in background + wait + + stop_lttng_tracing_ok "log4j2_before_start" + destroy_lttng_session_ok "log4j2_before_start" + + rm -f "${file_sync_after_first}" + rm -f "${file_sync_before_last}" + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH" +} + +function test_log4j2_after_start () +{ + diag "Test LOG4J2 application AFTER tracing starts" + + create_lttng_session_ok "log4j2_after_start" "$TRACE_PATH" + enable_log4j_lttng_event "log4j2_after_start" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_after_start" + + # Run 6 times with a 100ms delay + run_app + + stop_lttng_tracing_ok "log4j2_after_start" + destroy_lttng_session_ok "log4j2_after_start" + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH" +} + +function test_log4j2_loglevel () +{ + diag "Test LOG4J2 application with loglevel" + + create_lttng_session_ok "log4j2_loglevel_info" "$TRACE_PATH" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_info" $EVENT_NAME1 "LOG4J_INFO" + start_lttng_tracing_ok "log4j2_loglevel_info" + + # Run 6 times with a 1ms delay + run_app + + stop_lttng_tracing_ok "log4j2_loglevel_info" + destroy_lttng_session_ok "log4j2_loglevel_info" + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH" + + diag "Test LOG4J2 applications with lower loglevel" + + create_lttng_session_ok "log4j2_loglevel_fatal" "$TRACE_PATH" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_fatal" $EVENT_NAME1 "LOG4J_FATAL" + start_lttng_tracing_ok "log4j2_loglevel_fatal" + + # Run 6 times with a 1ms delay + run_app + + stop_lttng_tracing_ok "log4j2_loglevel_fatal" + destroy_lttng_session_ok "log4j2_loglevel_fatal" + + # Validate test. Expecting 0 events. + trace_match_only $EVENT_NAME1 0 "$TRACE_PATH" + + diag "Test LOG4J2 applications with higher loglevel" + + create_lttng_session_ok "log4j2_loglevel_trace" "$TRACE_PATH" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_trace" $EVENT_NAME1 "LOG4J_TRACE" + start_lttng_tracing_ok "log4j2_loglevel_trace" + + # Run 6 times with a 1ms delay + run_app + + stop_lttng_tracing_ok "log4j2_loglevel_trace" + destroy_lttng_session_ok "log4j2_loglevel_trace" + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH" +} + +function test_log4j2_loglevel_multiple () +{ + diag "Test LOG4J2 application with multiple loglevel" + + create_lttng_session_ok "log4j2_loglevel_multiple" "$TRACE_PATH" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_multiple" $EVENT_NAME1 "LOG4J_INFO" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_multiple" $EVENT_NAME1 "LOG4J_DEBUG" + start_lttng_tracing_ok "log4j2_loglevel_multiple" + + # Run 6 times with a 1ms delay and fire two TP. + run_app 1 + + stop_lttng_tracing_ok "log4j2_loglevel_multiple" + destroy_lttng_session_ok "log4j2_loglevel_multiple" + + # Validate test. Expecting all events times two. + trace_match_only $EVENT_NAME1 $((NR_ITER * 2)) "$TRACE_PATH" + + create_lttng_session_ok "log4j2_loglevel_multiple" "$TRACE_PATH" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_multiple" '*' "LOG4J_INFO" + enable_log4j_lttng_event_loglevel "log4j2_loglevel_multiple" '*' "LOG4J_DEBUG" + start_lttng_tracing_ok "log4j2_loglevel_multiple" + + # Run 6 times with a 1ms delay and fire two TP. + run_app 1 + + stop_lttng_tracing_ok "log4j2_loglevel_multiple" + destroy_lttng_session_ok "log4j2_loglevel_multiple" + + # Validate test. Expecting all events times two. + trace_match_only $EVENT_NAME1 $((NR_ITER * 2)) "$TRACE_PATH" +} + +function test_log4j2_multi_session_loglevel() +{ + diag "Test LOG4J2 with multiple session" + + create_lttng_session_ok "log4j2_all_info" "$TRACE_PATH/log4j2_all_info" + enable_log4j_lttng_event_loglevel_only "log4j2_all_info" '*' "LOG4J_INFO" + start_lttng_tracing_ok "log4j2_all_info" + + create_lttng_session_ok "log4j2_all_debug" "$TRACE_PATH/log4j2_all_debug" + enable_log4j_lttng_event_loglevel_only "log4j2_all_debug" '*' "LOG4J_DEBUG" + start_lttng_tracing_ok "log4j2_all_debug" + + # Run 6 times with a 1ms delay and fire second TP. + run_app 1 1 + + stop_lttng_tracing_ok "log4j2_all_info" + stop_lttng_tracing_ok "log4j2_all_debug" + destroy_lttng_session_ok "log4j2_all_info" + destroy_lttng_session_ok "log4j2_all_debug" + + # Expecting 7 events being the main event plus the second tp. + trace_match_only $EVENT_NAME_BASE $((NR_ITER + 1)) "$TRACE_PATH/log4j2_all_info" + + # Expectin 6 events being the debug TP. + trace_match_only $EVENT_NAME_BASE $NR_ITER "$TRACE_PATH/log4j2_all_debug" +} + +function test_log4j2_multi_session_disable() +{ + diag "Test LOG4J2 with multiple session with disabled event" + + create_lttng_session_ok "log4j2_disabled_event" "$TRACE_PATH/log4j2_disabled_event" + enable_log4j_lttng_event "log4j2_disabled_event" $EVENT_NAME1 + enable_log4j_lttng_event "log4j2_disabled_event" $EVENT_NAME2 + disable_log4j_lttng_event "log4j2_disabled_event" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_disabled_event" + + create_lttng_session_ok "log4j2_enabled_event" "$TRACE_PATH/log4j2_enabled_event" + enable_log4j_lttng_event "log4j2_enabled_event" $EVENT_NAME2 + start_lttng_tracing_ok "log4j2_enabled_event" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disabled_event" + stop_lttng_tracing_ok "log4j2_enabled_event" + destroy_lttng_session_ok "log4j2_disabled_event" + destroy_lttng_session_ok "log4j2_enabled_event" + + # Validate test. Expecting one event of the second TP. + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/log4j2_disabled_event" + + # Validate test. Expecting one event of the second TP. + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/log4j2_enabled_event" +} + +function test_log4j2_multi_session_disable_wildcard() +{ + diag "Test LOG4J2 with multiple session with disabled wildcard event" + + create_lttng_session_ok "log4j2_disabled_wildcard" "$TRACE_PATH/log4j2_disabled_wildcard" + enable_log4j_lttng_event "log4j2_disabled_wildcard" '*' + + create_lttng_session_ok "log4j2_enabled_wildcard" "$TRACE_PATH/log4j2_enabled_wildcard" + enable_log4j_lttng_event "log4j2_enabled_wildcard" '*' + + disable_log4j_lttng_event "log4j2_disabled_wildcard" '*' + + start_lttng_tracing_ok "log4j2_disabled_wildcard" + start_lttng_tracing_ok "log4j2_enabled_wildcard" + + run_app + + stop_lttng_tracing_ok "log4j2_disabled_wildcard" + stop_lttng_tracing_ok "log4j2_enabled_wildcard" + destroy_lttng_session_ok "log4j2_disabled_wildcard" + destroy_lttng_session_ok "log4j2_enabled_wildcard" + + # Validate test. Expecting NO event of the first TP. + trace_match_only $EVENT_NAME_BASE 0 "$TRACE_PATH/log4j2_disabled_wildcard" + + # Validate test. Expecting all events of the first TP. + trace_match_only $EVENT_NAME_BASE $NR_ITER "$TRACE_PATH/log4j2_enabled_wildcard" +} + +function test_log4j2_multi_session_disable_wildcard_begin() +{ + ev_name='*-event-1' + diag "Test LOG4J2 with multiple session with disabled wildcard (at the beginning) event" + + create_lttng_session_ok "log4j2_disabled_wildcard" "$TRACE_PATH/log4j2_disabled_wildcard" + enable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + create_lttng_session_ok "log4j2_enabled_wildcard" "$TRACE_PATH/log4j2_enabled_wildcard" + enable_log4j_lttng_event "log4j2_enabled_wildcard" "$ev_name" + + disable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + start_lttng_tracing_ok "log4j2_disabled_wildcard" + start_lttng_tracing_ok "log4j2_enabled_wildcard" + + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disabled_wildcard" + stop_lttng_tracing_ok "log4j2_enabled_wildcard" + destroy_lttng_session_ok "log4j2_disabled_wildcard" + destroy_lttng_session_ok "log4j2_enabled_wildcard" + + # Validate test. Expecting NO event of the first TP. + trace_match_only $EVENT_NAME1 0 "$TRACE_PATH/log4j2_disabled_wildcard" + + # Validate test. Expecting all events of the first TP. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH/log4j2_enabled_wildcard" +} + +function test_log4j2_multi_session_disable_wildcard_middle() +{ + ev_name='log*nt-1' + diag "Test LOG4J2 with multiple session with disabled wildcard (at the middle) event" + + create_lttng_session_ok "log4j2_disabled_wildcard" "$TRACE_PATH/log4j2_disabled_wildcard" + enable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + create_lttng_session_ok "log4j2_enabled_wildcard" "$TRACE_PATH/log4j2_enabled_wildcard" + enable_log4j_lttng_event "log4j2_enabled_wildcard" "$ev_name" + + disable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + start_lttng_tracing_ok "log4j2_disabled_wildcard" + start_lttng_tracing_ok "log4j2_enabled_wildcard" + + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disabled_wildcard" + stop_lttng_tracing_ok "log4j2_enabled_wildcard" + destroy_lttng_session_ok "log4j2_disabled_wildcard" + destroy_lttng_session_ok "log4j2_enabled_wildcard" + + # Validate test. Expecting NO event of the first TP. + trace_match_only $EVENT_NAME1 0 "$TRACE_PATH/log4j2_disabled_wildcard" + + # Validate test. Expecting all events of the first TP. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH/log4j2_enabled_wildcard" +} + +function test_log4j2_multi_session_disable_wildcard_end() +{ + ev_name='log4j2-ev*' + diag "Test LOG4J2 with multiple session with disabled wildcard (at the end) event" + + create_lttng_session_ok "log4j2_disabled_wildcard" "$TRACE_PATH/log4j2_disabled_wildcard" + enable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + create_lttng_session_ok "log4j2_enabled_wildcard" "$TRACE_PATH/log4j2_enabled_wildcard" + enable_log4j_lttng_event "log4j2_enabled_wildcard" "$ev_name" + + disable_log4j_lttng_event "log4j2_disabled_wildcard" "$ev_name" + + start_lttng_tracing_ok "log4j2_disabled_wildcard" + start_lttng_tracing_ok "log4j2_enabled_wildcard" + + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disabled_wildcard" + stop_lttng_tracing_ok "log4j2_enabled_wildcard" + destroy_lttng_session_ok "log4j2_disabled_wildcard" + destroy_lttng_session_ok "log4j2_enabled_wildcard" + + # Validate test. Expecting NO event of the first TP. + trace_match_only $EVENT_NAME_BASE 0 "$TRACE_PATH/log4j2_disabled_wildcard" + + # Validate test. Expecting all events of the first TP. + trace_matches $EVENT_NAME_BASE $(( NR_ITER + 1 )) "$TRACE_PATH/log4j2_enabled_wildcard" + + trace_matches $EVENT_NAME2 1 "$TRACE_PATH/log4j2_enabled_wildcard" +} + +function test_log4j2_disable_all() +{ + diag "Test LOG4J2 with multiple session with disabled all event" + + create_lttng_session_ok "log4j2_disable_all" "$TRACE_PATH/log4j2_disable_all" + enable_log4j_lttng_event "log4j2_disable_all" '*' + enable_log4j_lttng_event "log4j2_disable_all" $EVENT_NAME1 + enable_log4j_lttng_event "log4j2_disable_all" $EVENT_NAME2 + + disable_log4j_lttng_event "log4j2_disable_all" -a + + start_lttng_tracing_ok "log4j2_disable_all" + + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disable_all" + destroy_lttng_session_ok "log4j2_disable_all" + + # Validate test. Expecting NO event of the first TP and second TP. + trace_match_only $EVENT_NAME1 0 "$TRACE_PATH/log4j2_disable_all" + trace_match_only $EVENT_NAME2 0 "$TRACE_PATH/log4j2_disable_all" +} + +function test_log4j2_multi_session() +{ + diag "Test LOG4J2 with multiple session" + + create_lttng_session_ok "log4j2_multi_session_1" "$TRACE_PATH/log4j2_multi_session_1" + enable_log4j_lttng_event "log4j2_multi_session_1" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_multi_session_1" + + create_lttng_session_ok "log4j2_multi_session_2" "$TRACE_PATH/log4j2_multi_session_2" + enable_log4j_lttng_event "log4j2_multi_session_2" $EVENT_NAME2 + start_lttng_tracing_ok "log4j2_multi_session_2" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_multi_session_1" + stop_lttng_tracing_ok "log4j2_multi_session_2" + destroy_lttng_session_ok "log4j2_multi_session_1" + destroy_lttng_session_ok "log4j2_multi_session_2" + + # Validate test. Expecting all events of first TP + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH/log4j2_multi_session_1" + + # Validate test. Expecting one event of the second TP. + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/log4j2_multi_session_2" +} + +function test_log4j2_destroy_session() +{ + diag "Test LOG4J2 two session with destroy" + + create_lttng_session_ok "log4j2_destroy_session" "$TRACE_PATH/first-sess" + enable_log4j_lttng_event "log4j2_destroy_session" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_destroy_session" + + # Run 5 times with a 1ms delay + run_app_background 0 1 + # Wait for the applications started in background + wait + + stop_lttng_tracing_ok "log4j2_destroy_session" + destroy_lttng_session_ok "log4j2_destroy_session" + + # Validate test. Expecting at least one event num 1 + validate_trace $EVENT_NAME1 "$TRACE_PATH/first-sess" + + create_lttng_session_ok "log4j2_destroy_session" "$TRACE_PATH/second-sess" + enable_log4j_lttng_event "log4j2_destroy_session" $EVENT_NAME2 + start_lttng_tracing_ok "log4j2_destroy_session" + + # Run 5 times with a 1ms delay + run_app_background 0 1 + # Wait for the applications started in background + wait + + stop_lttng_tracing_ok "log4j2_destroy_session" + destroy_lttng_session_ok "log4j2_destroy_session" + + # Validate test. Expecting only one event num 2 + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/second-sess" +} + +function test_log4j2_filtering() +{ + diag "Test LOG4J2 filtering" + + create_lttng_session_ok "log4j2_filtering" "$TRACE_PATH/log4j2_filtering" + # Enable all event with a filter. + enable_log4j_lttng_event_filter "log4j2_filtering" '*' 'msg == "LOG4J2 INFO second logger fired"' + start_lttng_tracing_ok "log4j2_filtering" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_filtering" + destroy_lttng_session_ok "log4j2_filtering" + + # Validate test. Expecting one event of the second TP only. + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/log4j2_filtering" + + create_lttng_session_ok "log4j2_filtering" "$TRACE_PATH/log4j2_filtering" + # Enable first Logger but filter msg payload for the INFO one while + # triggering the debug and second TP. + enable_log4j_lttng_event_filter "log4j2_filtering" $EVENT_NAME1 'msg == "LOG4J2 INFO tp fired!"' + start_lttng_tracing_ok "log4j2_filtering" + + # Run 5 times with a 1ms delay, fire debug and second TP. + run_app 1 1 + + stop_lttng_tracing_ok "log4j2_filtering" + destroy_lttng_session_ok "log4j2_filtering" + + # Validate test. Expecting NR_ITER event of the main INFO tp. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH/log4j2_filtering" +} + +function test_log4j2_disable() +{ + diag "Test LOG4J2 disable event" + + create_lttng_session_ok "log4j2_disable" "$TRACE_PATH/log4j2_disable" + # Enable all event with a filter. + enable_log4j_lttng_event "log4j2_disable" $EVENT_NAME1 + enable_log4j_lttng_event "log4j2_disable" $EVENT_NAME2 + disable_log4j_lttng_event "log4j2_disable" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_disable" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disable" + destroy_lttng_session_ok "log4j2_disable" + + # Validate test. Expecting one event of the second TP only. + trace_match_only $EVENT_NAME2 1 "$TRACE_PATH/log4j2_disable" +} + +function test_log4j2_disable_enable() +{ + diag "Test LOG4J2 disable event followed by an enable" + + create_lttng_session_ok "log4j2_disable_enable" "$TRACE_PATH/log4j2_disable_enable" + # Enable all event with a filter. + enable_log4j_lttng_event "log4j2_disable_enable" $EVENT_NAME1 + disable_log4j_lttng_event "log4j2_disable_enable" $EVENT_NAME1 + enable_log4j_lttng_event "log4j2_disable_enable" $EVENT_NAME1 + start_lttng_tracing_ok "log4j2_disable_enable" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_disable_enable" + destroy_lttng_session_ok "log4j2_disable_enable" + + # Validate test. Expecting NR_ITER event of the main INFO tp. + trace_match_only $EVENT_NAME1 $NR_ITER "$TRACE_PATH/log4j2_disable_enable" +} + +function test_log4j2_filter_loglevel() +{ + local bogus_event_name="not_a_real_event" + local filter="int_loglevel > 700 || int_loglevel < 700" + local all_events="." + + diag "Test LOG4J2 a filter with a loglevel" + + create_lttng_session_ok "log4j2_filter_info" "$TRACE_PATH/log4j2_filter_info" + # Enable an event with a filter and the loglevel-only option. + enable_log4j_lttng_event_filter_loglevel_only "log4j2_filter_info" $bogus_event_name "$filter" LOG4J_INFO + disable_log4j_lttng_event "log4j2_filter_info" $bogus_event_name + enable_log4j_lttng_event_filter_loglevel_only "log4j2_filter_info" $bogus_event_name "$filter" LOG4J_INFO + start_lttng_tracing_ok "log4j2_filter_info" + + # Run 5 times with a 1ms delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing_ok "log4j2_filter_info" + destroy_lttng_session_ok "log4j2_filter_info" + + # Validate test. Expecting no events. + trace_match_only $all_events 0 "$TRACE_PATH/log4j2_filter_info" +} + +plan_tests $NUM_TESTS + +print_test_banner "$TEST_DESC" + +bail_out_if_no_babeltrace + +test -f "$TESTAPP_PATH.class" +ok $? "Testapp '$TESTAPP_NAME' present" + +start_lttng_sessiond + +tests=( + test_log4j2_multi_session_disable_wildcard + test_log4j2_multi_session_disable_wildcard_begin + test_log4j2_multi_session_disable_wildcard_middle + test_log4j2_multi_session_disable_wildcard_end + test_log4j2_multi_session_disable + test_log4j2_disable + test_log4j2_disable_enable + test_log4j2_disable_all + test_log4j2_filtering + test_log4j2_multi_session_loglevel + test_log4j2_destroy_session + test_log4j2_loglevel + test_log4j2_loglevel_multiple + test_log4j2_before_start + test_log4j2_after_start + test_log4j2_multi_session + test_log4j2_filter_loglevel +) + +for fct_test in "${tests[@]}"; +do + TRACE_PATH=$(mktemp --tmpdir -d tmp.test_java_log4j2_trace_path.XXXXXX) + + ${fct_test} + + rm -rf "$TRACE_PATH" +done + +stop_lttng_sessiond diff --git a/tests/utils/utils.sh b/tests/utils/utils.sh index 1e7d88b76..e23626309 100644 --- a/tests/utils/utils.sh +++ b/tests/utils/utils.sh @@ -238,6 +238,20 @@ function validate_lttng_modules_present () LTTNG_BAIL_OUT "LTTng modules not detected." } +# Run the lttng binary. +# +# The first two arguments are stdout and stderr redirect paths, respectively. +# The rest of the arguments are forwarded to the lttng binary +function _run_lttng_cmd +{ + local stdout_dest="$1" + local stderr_dest="$2" + shift 2 + + diag "$TESTDIR/../src/bin/lttng/$LTTNG_BIN $*" + $TESTDIR/../src/bin/lttng/$LTTNG_BIN "$@" 1> "$stdout_dest" 2> "$stderr_dest" +} + function enable_kernel_lttng_event { local withtap="$1" @@ -1259,37 +1273,80 @@ function enable_jul_lttng_event_loglevel() function enable_log4j_lttng_event() { - sess_name=$1 - event_name="$2" - channel_name=$3 + local sess_name=$1 + local event_name=$2 + local channel_name=$3 - if [ -z $channel_name ]; then - # default channel if none specified - chan="" - else - chan="-c $channel_name" + local chan_opt=() + + # default channel if none specified + if [ -n "$channel_name" ]; then + chan_opt=("-c" "$channel_name") fi - $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "$event_name" $chan -s $sess_name -l 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST - ok $? "Enable LOG4J event $event_name for session $sess_name" + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + enable-event "$event_name" "${chan_opt[@]}" -s "$sess_name" --log4j + ok $? "Enable LOG4J event '$event_name' for session '$sess_name'" +} + +function enable_log4j_lttng_event_filter() +{ + local sess_name=$1 + local event_name=$2 + local filter=$3 + + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + enable-event "$event_name" -s "$sess_name" --log4j --filter "$filter" + ok $? "Enable LOG4J event '$event_name' with filter '$filter' for session '$sess_name'" +} + +function enable_log4j_lttng_event_filter_loglevel_only() +{ + local sess_name=$1 + local event_name=$2 + local filter=$3 + local loglevel=$4 + + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + enable-event --loglevel-only "$loglevel" "$event_name" -s "$sess_name" -l --filter "$filter" + ok $? "Enable LOG4J event '$event_name' with filter '$filter' and loglevel-only '$loglevel' for session '$sess_name'" } function enable_log4j_lttng_event_loglevel() { local sess_name=$1 - local event_name="$2" + local event_name=$2 local loglevel=$3 local channel_name=$4 - if [ -z $channel_name ]; then - # default channel if none specified - chan="" - else - chan="-c $channel_name" + + # default channel if none specified + if [ -n "$channel_name" ]; then + chan_opt=("-c" "$channel_name") + fi + + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + enable-event --loglevel "$loglevel" "$event_name" "${chan_opt[@]}" -s "$sess_name" --log4j + ok $? "Enable LOG4J event '$event_name' for session '$sess_name' with loglevel '$loglevel'" +} + +function enable_log4j_lttng_event_loglevel_only() +{ + local sess_name=$1 + local event_name=$2 + local loglevel=$3 + local channel_name=$4 + + local chan_opt=() + + # default channel if none specified + if [ -n "$channel_name" ]; then + chan_opt=("-c" "$channel_name") fi - $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event --loglevel $loglevel "$event_name" $chan -s $sess_name -l 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST - ok $? "Enable LOG4J event $event_name for session $sess_name with loglevel $loglevel" + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + enable-event --loglevel-only "$loglevel" "$event_name" "${chan_opt[@]}" -s "$sess_name" --log4j + ok $? "Enable LOG4J event '$event_name' for session '$sess_name' with loglevel-only '$loglevel'" } function enable_python_lttng_event() @@ -1396,8 +1453,9 @@ function disable_log4j_lttng_event () local sess_name="$1" local event_name="$2" - $TESTDIR/../src/bin/lttng/$LTTNG_BIN disable-event "$event_name" -s $sess_name -l >/dev/null 2>&1 - ok $? "Disable LOG4J event $event_name for session $sess_name" + _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ + disable-event "$event_name" -s "$sess_name" --log4j + ok $? "Disable LOG4J event '$event_name' for session '$sess_name'" } function disable_python_lttng_event () @@ -1801,6 +1859,14 @@ function wait_live_viewer_connect () pass "Waiting for live viewers on url: $url" } +function bail_out_if_no_babeltrace() +{ + which "$BABELTRACE_BIN" >/dev/null + if [ $? -ne 0 ]; then + LTTNG_BAIL_OUT "\"$BABELTRACE_BIN\" binary not found. Skipping tests" + fi +} + function validate_metadata_event () { local event_name=$1