From f363038e145a56000d9479258360f742fd9cda59 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 --- .../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 | 11 ++++++-- .../regression/ust/java-log4j/test_java_log4j | 11 ++++++-- .../regression/ust/nprocesses/test_nprocesses | 14 +++++++--- .../test_periodical_metadata_flush | 2 +- 9 files changed, 75 insertions(+), 25 deletions(-) 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 1535f3627..460b04c4e 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 0258e890c..c95a4a1f9 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 d16880f27..d32d9ed45 100755 --- a/tests/regression/ust/java-jul/test_java_jul +++ b/tests/regression/ust/java-jul/test_java_jul @@ -38,6 +38,7 @@ function run_app local finest_tp=$1 local fire_second_tp=$2 + #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 } @@ -89,6 +90,9 @@ function enable_jul_filter_loglevel_only() 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 @@ -96,16 +100,19 @@ function test_jul_before_start () # Run 5 times with a 1 second delay run_app_background - #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_match_only $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 index 11845a0bb..a0b7cdc0f 100755 --- a/tests/regression/ust/java-log4j/test_java_log4j +++ b/tests/regression/ust/java-log4j/test_java_log4j @@ -39,6 +39,7 @@ 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 } @@ -90,6 +91,9 @@ function enable_log4j_filter_loglevel_only() 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 @@ -97,16 +101,19 @@ function test_log4j_before_start () # Run 5 times with a 1 second delay run_app_background - #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_match_only $EVENT_NAME $NR_ITER $TRACE_PATH if [ $? -ne 0 ]; then 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