From 75b7424d0f60dc23ca0d33ba21eab19f7715509b Mon Sep 17 00:00:00 2001 From: Mathieu Desnoyers Date: Thu, 20 Nov 2014 07:40:41 +0100 Subject: [PATCH] Fix: add missing synchronization point for before app test case MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Fixes a race where the application could generate all its events before trace start. Signed-off-by: Mathieu Desnoyers Signed-off-by: Jérémie Galarneau Conflicts: tests/utils/testapp/gen-ust-events/gen-ust-events.c Conflicts: tests/regression/ust/java-jul/test_java_jul tests/regression/ust/java-log4j/test_java_log4j --- .../tools/snapshots/test_ust_streaming | 2 +- tests/regression/tools/snapshots/ust_test | 2 +- tests/regression/tools/streaming/test_ust | 21 +- .../ust/before-after/test_before_after | 11 +- .../ust/buffers-pid/test_buffers_pid | 26 +- tests/regression/ust/java-jul/test_java_jul | 13 +- .../regression/ust/java-log4j/test_java_log4j | 601 ++++++++++++++++++ .../regression/ust/nprocesses/test_nprocesses | 14 +- .../test_periodical_metadata_flush | 2 +- 9 files changed, 668 insertions(+), 24 deletions(-) create mode 100755 tests/regression/ust/java-log4j/test_java_log4j diff --git a/tests/regression/tools/snapshots/test_ust_streaming b/tests/regression/tools/snapshots/test_ust_streaming index 55c1087d9..ef38bd599 100755 --- a/tests/regression/tools/snapshots/test_ust_streaming +++ b/tests/regression/tools/snapshots/test_ust_streaming @@ -58,7 +58,7 @@ function snapshot_add_output () # Start trace application and return once one event has been hit. function start_test_app() { - local tmp_file="/tmp/lttng_test_ust.42.file" + local tmp_file=$(mktemp -u) # Start application with a temporary file. $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT $tmp_file & diff --git a/tests/regression/tools/snapshots/ust_test b/tests/regression/tools/snapshots/ust_test index 552eed231..e839b84bf 100755 --- a/tests/regression/tools/snapshots/ust_test +++ b/tests/regression/tools/snapshots/ust_test @@ -49,7 +49,7 @@ NUM_TESTS=$(($NUM_TESTS + ($NR_SNAPSHOT * 2))) function start_test_app() { - local tmp_file="/tmp/lttng_test_ust.42.file" + local tmp_file=$(mktemp -u) # Start application with a temporary file. $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT $tmp_file & diff --git a/tests/regression/tools/streaming/test_ust b/tests/regression/tools/streaming/test_ust index 480717515..e6a0bb846 100755 --- a/tests/regression/tools/streaming/test_ust +++ b/tests/regression/tools/streaming/test_ust @@ -49,40 +49,51 @@ function lttng_create_session_uri function test_ust_before_start () { + local file_sync_after_first=$(mktemp -u) + local file_sync_before_last=$(mktemp -u) + diag "Test UST streaming BEFORE tracing starts" lttng_create_session_uri enable_ust_lttng_event $SESSION_NAME $EVENT_NAME # Run 5 times with a 1 second delay - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT >/dev/null 2>&1 & - - #FIXME: racy missing synchro + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} /dev/null 2>&1 & start_lttng_tracing $SESSION_NAME + + touch ${file_sync_before_last} + # Wait for the applications started in background wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + rm -f ${file_sync_after_first} + rm -f ${file_sync_before_last} } function test_ust_after_start () { + local file_sync_after_first=$(mktemp -u) + diag "Test UST streaming AFTER tracing starts" lttng_create_session_uri enable_ust_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing $SESSION_NAME # Run 5 times with a 1 second delay - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT >/dev/null 2>&1 + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} >/dev/null 2>&1 - #FIXME: racy missing synchro + while [ ! -f "${file_sync_after_first}" ]; do + sleep 0.5 + done stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME # Wait for the applications started in background wait + rm -f ${file_sync_after_first} } plan_tests $NUM_TESTS diff --git a/tests/regression/ust/before-after/test_before_after b/tests/regression/ust/before-after/test_before_after index 95ea33cc4..7e40c0621 100755 --- a/tests/regression/ust/before-after/test_before_after +++ b/tests/regression/ust/before-after/test_before_after @@ -57,22 +57,27 @@ function test_before_apps() function test_after_apps() { local out + local file_sync_after_first=$(mktemp -u) + local file_sync_before_last=$(mktemp -u) create_lttng_session $SESSION_NAME $TRACE_PATH enable_ust_lttng_event $SESSION_NAME $EVENT_NAME - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} & ok $? "Application started in background." - #FIXME: racy missing synchronization - start_lttng_tracing $SESSION_NAME + touch ${file_sync_before_last} + wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + rm -f ${file_sync_after_first} + rm -f ${file_sync_before_last} + validate_trace $EVENT_NAME $TRACE_PATH out=$? diff --git a/tests/regression/ust/buffers-pid/test_buffers_pid b/tests/regression/ust/buffers-pid/test_buffers_pid index f306613a1..759a5662f 100755 --- a/tests/regression/ust/buffers-pid/test_buffers_pid +++ b/tests/regression/ust/buffers-pid/test_buffers_pid @@ -74,22 +74,26 @@ test_after_multiple_apps() { test_before_multiple_apps() { local out local i + local file_sync_after_first=$(mktemp -u) + local file_sync_before_last=$(mktemp -u) diag "Start multiple applications BEFORE tracing is started" for i in `seq 1 5`; do - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT >/dev/null 2>&1 & + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first}_${i} ${file_sync_before_last}_${i} >/dev/null 2>&1 & ok $? "Start application $i for tracing" done - #FIXME: racy missing synchronization - # BEFORE application is spawned create_lttng_session $SESSION_NAME $TRACE_PATH enable_channel_per_pid $SESSION_NAME "channel0" enable_ust_lttng_event $SESSION_NAME $EVENT_NAME "channel0" start_lttng_tracing $SESSION_NAME + for i in `seq 1 5`; do + touch ${file_sync_before_last}_${i} + done + diag "Waiting for applications to end" wait pass "Waiting done" @@ -97,6 +101,11 @@ test_before_multiple_apps() { stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + for i in `seq 1 5`; do + rm -f ${file_sync_after_first}_${i} + rm -f ${file_sync_before_last}_${i} + done + out=$(babeltrace $TRACE_PATH | grep $EVENT_NAME | wc -l) if [ $out -eq 0 ]; then fail "Trace validation" @@ -136,6 +145,8 @@ test_after_app() { test_before_app() { local out + local file_sync_after_first=$(mktemp -u) + local file_sync_before_last=$(mktemp -u) diag "Start application BEFORE tracing is started" @@ -145,18 +156,21 @@ test_before_app() { enable_channel_per_pid $SESSION_NAME "channel0" enable_ust_lttng_event $SESSION_NAME $EVENT_NAME "channel0" - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} & ok $? "Start application to trace" - #FIXME: racy missing synchronization - start_lttng_tracing $SESSION_NAME + touch ${file_sync_before_last} + wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + rm -f ${file_sync_after_first} + rm -f ${file_sync_before_last} + out=$(babeltrace $TRACE_PATH | grep $EVENT_NAME | wc -l) if [ $out -eq 0 ]; then fail "Trace validation" diff --git a/tests/regression/ust/java-jul/test_java_jul b/tests/regression/ust/java-jul/test_java_jul index b707a6d4c..5c784940b 100755 --- a/tests/regression/ust/java-jul/test_java_jul +++ b/tests/regression/ust/java-jul/test_java_jul @@ -38,7 +38,8 @@ function run_app local finest_tp=$1 local fire_second_tp=$2 - java -cp $JAVA_CP -Djava.library.path="/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $finest_tp $fire_second_tp >/dev/null 2>&1 & + #FIXME: app should have synchro. + java -cp $JAVA_CP -Djava.library.path="/usr/local/lib:/usr/lib" $TESTAPP_NAME $NR_ITER $NR_MSEC_WAIT $finest_tp $fire_second_tp >/dev/null 2>&1 } function wait_apps @@ -81,6 +82,9 @@ function enable_jul_filter() function test_jul_before_start () { + local file_sync_after_first=$(mktemp -u) + local file_sync_before_last=$(mktemp -u) + diag "Test JUL application BEFORE tracing starts" create_lttng_session $SESSION_NAME $TRACE_PATH enable_jul_lttng_event $SESSION_NAME $EVENT_NAME @@ -88,16 +92,19 @@ function test_jul_before_start () # Run 5 times with a 1 second delay run_app - #FIXME: racy missing synchronization - start_lttng_tracing $SESSION_NAME + touch ${file_sync_before_last} + # Wait for the applications started in background wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + rm -f ${file_sync_after_first} + rm -f ${file_sync_before_last} + # Validate test. Expecting all events. trace_matches $EVENT_NAME $NR_ITER $TRACE_PATH if [ $? -ne 0 ]; then diff --git a/tests/regression/ust/java-log4j/test_java_log4j b/tests/regression/ust/java-log4j/test_java_log4j new file mode 100755 index 000000000..a0b7cdc0f --- /dev/null +++ b/tests/regression/ust/java-log4j/test_java_log4j @@ -0,0 +1,601 @@ +#!/bin/bash +# +# Copyright (C) - 2014 David Goulet +# +# This program is free software; you can redistribute it and/or modify it under +# the terms of the GNU General Public License, version 2 only, as published by +# the Free Software Foundation. +# +# 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, write to the Free Software Foundation, Inc., 51 +# Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + +TEST_DESC="Java LOG4J support" + +CURDIR=$(dirname $0)/ +TESTDIR=$CURDIR/../../.. +NR_ITER=6 +NR_MSEC_WAIT=1000 +TESTAPP_NAME="JTestLTTng" +TESTAPP_BIN="$TESTAPP_NAME.java" +TESTAPP_PATH="$CURDIR/$TESTAPP_NAME" +SESSION_NAME="log4j" +EVENT_NAME="log4j-event" +EVENT_NAME2="log4j-event-2" +JAVA_CP="$CURDIR:/usr/local/share/java/liblttng-ust-agent.jar:/usr/share/java/*" +OUTPUT_DEST="/dev/null" + +NUM_TESTS=155 + +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="/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 $@ & +} + +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" + 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" +} + +function enable_log4j_filter() +{ + 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" +} + +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 -u) + local file_sync_before_last=$(mktemp -u) + + diag "Test LOG4J application BEFORE tracing starts" + create_lttng_session $SESSION_NAME $TRACE_PATH + enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME + + # Run 5 times with a 1 second delay + run_app_background + + start_lttng_tracing $SESSION_NAME + + touch ${file_sync_before_last} + + # Wait for the applications started in background + wait + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + 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 +} + +function test_log4j_after_start () +{ + diag "Test LOG4J application AFTER tracing starts" + + create_lttng_session $SESSION_NAME $TRACE_PATH + enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH + if [ $? -ne 0 ]; then + return $? + fi +} + +function test_log4j_loglevel () +{ + diag "Test LOG4J application with loglevel" + + create_lttng_session $SESSION_NAME $TRACE_PATH + enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_INFO" + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH + if [ $? -ne 0 ]; then + return $? + fi + + diag "Test LOG4J applications with lower loglevel" + + create_lttng_session $SESSION_NAME $TRACE_PATH + enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_FATAL" + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + # Validate test. Expecting 0 events. + trace_match_only $EVENT_NAME 0 $TRACE_PATH + if [ $? -ne 0 ]; then + return $? + fi + + diag "Test LOG4J applications with higher loglevel" + + create_lttng_session $SESSION_NAME $TRACE_PATH + enable_log4j_lttng_event_loglevel $SESSION_NAME $EVENT_NAME "LOG4J_TRACE" + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + # Validate test. Expecting all events. + trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH + return $? +} + +function test_log4j_loglevel_multiple () +{ + diag "Test LOG4J application with multiple loglevel" + + create_lttng_session $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 $SESSION_NAME + + # Run 5 times with a 1 second delay and fire two TP. + run_app 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 + + create_lttng_session $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 $SESSION_NAME + + # Run 5 times with a 1 second delay and fire two TP. + run_app 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_multi_session_loglevel() +{ + diag "Test LOG4J with multiple session" + + create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + enable_log4j_loglevel_only $SESSION_NAME-1 '*' "LOG4J_INFO" + start_lttng_tracing $SESSION_NAME-1 + + create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + enable_log4j_loglevel_only $SESSION_NAME-2 '*' "LOG4J_DEBUG" + start_lttng_tracing $SESSION_NAME-2 + + # Run 5 times with a 1 second delay and fire second TP. + run_app 1 1 + + stop_lttng_tracing $SESSION_NAME-1 + stop_lttng_tracing $SESSION_NAME-2 + destroy_lttng_session $SESSION_NAME-1 + destroy_lttng_session $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 + + # 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 +} + +function test_log4j_multi_session_disable() +{ + diag "Test LOG4J with multiple session with disabled event" + + create_lttng_session $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 $SESSION_NAME-1 + + create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2 + start_lttng_tracing $SESSION_NAME-2 + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME-1 + stop_lttng_tracing $SESSION_NAME-2 + destroy_lttng_session $SESSION_NAME-1 + destroy_lttng_session $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 + + # 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 +} + +function test_log4j_multi_session_disable_wildcard() +{ + diag "Test LOG4J with multiple session with disabled wildcard event" + + create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + enable_log4j_lttng_event $SESSION_NAME-1 '*' + + create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + enable_log4j_lttng_event $SESSION_NAME-2 '*' + + disable_log4j_lttng_event $SESSION_NAME-1 '*' + + start_lttng_tracing $SESSION_NAME-1 + start_lttng_tracing $SESSION_NAME-2 + + run_app + + stop_lttng_tracing $SESSION_NAME-1 + stop_lttng_tracing $SESSION_NAME-2 + destroy_lttng_session $SESSION_NAME-1 + destroy_lttng_session $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 + + # 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 +} + +function test_log4j_disable_all() +{ + diag "Test LOG4J with multiple session with disabled all event" + + create_lttng_session $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 + + disable_log4j_lttng_event $SESSION_NAME '*' + + start_lttng_tracing $SESSION_NAME + + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_multi_session() +{ + diag "Test LOG4J with multiple session" + + create_lttng_session $SESSION_NAME-1 $TRACE_PATH/$SESSION_NAME-1 + enable_log4j_lttng_event $SESSION_NAME-1 $EVENT_NAME + start_lttng_tracing $SESSION_NAME-1 + + create_lttng_session $SESSION_NAME-2 $TRACE_PATH/$SESSION_NAME-2 + enable_log4j_lttng_event $SESSION_NAME-2 $EVENT_NAME2 + start_lttng_tracing $SESSION_NAME-2 + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME-1 + stop_lttng_tracing $SESSION_NAME-2 + destroy_lttng_session $SESSION_NAME-1 + destroy_lttng_session $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 + + # 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 +} + +function test_log4j_destroy_session() +{ + diag "Test LOG4J two session with destroy" + + create_lttng_session $SESSION_NAME $TRACE_PATH/first-sess + enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app_background 0 1 + # Wait for the applications started in background + wait + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 + + create_lttng_session $SESSION_NAME $TRACE_PATH/second-sess + enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME2 + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay + run_app_background 0 1 + # Wait for the applications started in background + wait + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_filtering() +{ + diag "Test LOG4J filtering" + + create_lttng_session $SESSION_NAME $TRACE_PATH/$SESSION_NAME + # Enable all event with a filter. + enable_log4j_filter $SESSION_NAME '*' 'msg == "LOG4J second logger fired"' + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 + + create_lttng_session $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!"' + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay, fire debug and second TP. + run_app 1 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_disable() +{ + diag "Test LOG4J disable event" + + create_lttng_session $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 + disable_log4j_lttng_event $SESSION_NAME $EVENT_NAME + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_disable_enable() +{ + diag "Test LOG4J disable event followed by an enable" + + create_lttng_session $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 + enable_log4j_lttng_event $SESSION_NAME $EVENT_NAME + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $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 +} + +function test_log4j_filter_loglevel() +{ + local BOGUS_EVENT_NAME="not_a_real_event" + local FILTER="int_loglevel > 700 || int_loglevel < 700" + local ALL_EVENTS="." + + diag "Test LOG4J a filter with a loglevel" + + create_lttng_session $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 + disable_log4j_lttng_event $SESSION_NAME $BOGUS_EVENT_NAME + enable_log4j_filter_loglevel_only $SESSION_NAME $BOGUS_EVENT_NAME "$FILTER" LOG4J_INFO + start_lttng_tracing $SESSION_NAME + + # Run 5 times with a 1 second delay and fire second TP. + run_app 0 1 + + stop_lttng_tracing $SESSION_NAME + destroy_lttng_session $SESSION_NAME + + # Validate test. Expecting no events. + trace_match_only $ALL_EVENTS 0 $TRACE_PATH/$SESSION_NAME + if [ $? -ne 0 ]; then + return $? + fi +} + +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 + 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 -d) + + ${fct_test} + if [ $? -ne 0 ]; then + break; + fi + rm -rf $TRACE_PATH + done + + stop_lttng_sessiond +} diff --git a/tests/regression/ust/nprocesses/test_nprocesses b/tests/regression/ust/nprocesses/test_nprocesses index ca0f9d416..8eed95fca 100755 --- a/tests/regression/ust/nprocesses/test_nprocesses +++ b/tests/regression/ust/nprocesses/test_nprocesses @@ -46,15 +46,16 @@ start_lttng_sessiond # Start tests. Each is an infinite tracing loop. +file_sync_after_first=$(mktemp -u) +file_sync_before_last=$(mktemp -u) + diag "Starting $NUM_PROCESS test applications" for i in `seq 1 $NUM_PROCESS` do - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT >/dev/null 2>&1 & + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} >/dev/null 2>&1 & APPS_PID="${APPS_PID} ${!}" done -#FIXME: racy missing synchronization - diag "Waiting for applications to be registered to sessiond" reg_app_count=0 @@ -72,13 +73,15 @@ create_lttng_session $SESSION_NAME $TRACE_PATH enable_ust_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing $SESSION_NAME +touch ${file_sync_before_last} + # We don't validate whether the applications have traced here, rather # just that they registered to sessiond (above). stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME -#FIXME/TODO: add validation after fixing racy synchroniaation +#TODO: add trace validation. rm -rf $TRACE_PATH @@ -90,4 +93,7 @@ done APPS_PID= pass "Stopped all spawned applications" +rm -f ${file_sync_after_first} +rm -f ${file_sync_before_last} + stop_lttng_sessiond diff --git a/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush b/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush index 53db813e1..7937fa27d 100755 --- a/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush +++ b/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush @@ -27,7 +27,7 @@ SESSION_NAME="periodical-flush" EVENT_NAME="tp:tptest" BIN_NAME="gen-nevents" NUM_TESTS=38 -APP_TMP_FILE="/tmp/lttng_test_ust.42.file" +APP_TMP_FILE=$(mktemp -u) APPS_PID= source $TESTDIR/utils/utils.sh -- 2.34.1