From 993ae90ddf956c573c1da463adbd21333bee9106 Mon Sep 17 00:00:00 2001 From: Mathieu Desnoyers Date: Wed, 19 Nov 2014 22:40:28 +0100 Subject: [PATCH] Fix: tests: add missing wait, document missing synchro MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Move all wait ${!} that target a single process to "wait", to minimize the chances to forget some background process in the future. Signed-off-by: Mathieu Desnoyers Signed-off-by: Jérémie Galarneau Conflicts: tests/regression/ust/java-log4j/test_java_log4j Conflicts: tests/regression/tools/streaming/test_ust tests/regression/ust/before-after/test_before_after tests/regression/ust/buffers-pid/test_buffers_pid tests/regression/ust/multi-session/test_multi_session --- .../tools/snapshots/test_ust_streaming | 1 + tests/regression/tools/snapshots/ust_test | 1 + tests/regression/tools/streaming/test_ust | 13 +++- .../ust/before-after/test_before_after | 36 +++++----- .../ust/buffers-pid/test_buffers_pid | 46 +++++++++---- .../ust/high-throughput/test_high_throughput | 2 +- tests/regression/ust/java-jul/test_java_jul | 2 + .../ust/multi-session/test_multi_session | 6 +- .../regression/ust/nprocesses/test_nprocesses | 5 ++ .../test_periodical_metadata_flush | 68 +++++++++++++++---- 10 files changed, 125 insertions(+), 55 deletions(-) diff --git a/tests/regression/tools/snapshots/test_ust_streaming b/tests/regression/tools/snapshots/test_ust_streaming index 52330a5c9..ad0c56b19 100755 --- a/tests/regression/tools/snapshots/test_ust_streaming +++ b/tests/regression/tools/snapshots/test_ust_streaming @@ -82,6 +82,7 @@ function stop_test_apps() kill ${p} wait ${p} 2>&1 done + APPS_PID= } # Test a snapshot using a default name for the output destination. diff --git a/tests/regression/tools/snapshots/ust_test b/tests/regression/tools/snapshots/ust_test index 9dd95bf2b..d8ab18880 100755 --- a/tests/regression/tools/snapshots/ust_test +++ b/tests/regression/tools/snapshots/ust_test @@ -73,6 +73,7 @@ function stop_test_apps() kill ${p} wait ${p} 2>&1 done + APPS_PID= } function snapshot_add_output () diff --git a/tests/regression/tools/streaming/test_ust b/tests/regression/tools/streaming/test_ust index 785a9a835..d96db9460 100755 --- a/tests/regression/tools/streaming/test_ust +++ b/tests/regression/tools/streaming/test_ust @@ -29,7 +29,7 @@ PID_RELAYD=0 TRACE_PATH=$(mktemp -d) -NUM_TESTS=18 +NUM_TESTS=16 source $TESTDIR/utils/utils.sh @@ -63,9 +63,11 @@ function test_ust_before_start () # Run 5 times with a 1 second delay $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT >/dev/null 2>&1 & - start_lttng_tracing $SESSION_NAME + #FIXME: racy missing synchro - wait_apps + start_lttng_tracing $SESSION_NAME + # Wait for the applications started in background + wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME @@ -83,8 +85,13 @@ function test_ust_after_start () wait_apps + #FIXME: racy missing synchro + stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME + + # Wait for the applications started in background + wait } 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 ed4981ba0..460b04c4e 100755 --- a/tests/regression/ust/before-after/test_before_after +++ b/tests/regression/ust/before-after/test_before_after @@ -25,7 +25,7 @@ TESTAPP_NAME="gen-ust-events" TESTAPP_BIN="$TESTAPP_PATH/$TESTAPP_NAME/$TESTAPP_NAME" SESSION_NAME="per-session" EVENT_NAME="tp:tptest" -NUM_TESTS=17 +NUM_TESTS=16 source $TESTDIR/utils/utils.sh @@ -35,14 +35,6 @@ fi # MUST set TESTDIR before calling those functions -function wait_app() -{ - while [ -n "$(pidof $TESTAPP_NAME)" ]; do - sleep 0.5 - done - pass "Application $TESTAPP_NAME ended." -} - function test_before_apps() { # BEFORE application is spawned @@ -50,13 +42,14 @@ function test_before_apps() enable_ust_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing $SESSION_NAME - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & + wait ok $? "Traced application stopped." stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - trace_matches $EVENT_NAME $NR_ITER $TRACE_PATH + trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH return $? } @@ -64,24 +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) - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & - ok $? "Application started in background." - - # BEFORE application is spawned create_lttng_session $SESSION_NAME $TRACE_PATH enable_ust_lttng_event $SESSION_NAME $EVENT_NAME + + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} & + ok $? "Application started in background." + start_lttng_tracing $SESSION_NAME - # Since the start is done after the application is started, there is a - # bootstrap time needed between the session daemon and the UST tracer. - # Waiting for the application to end tells us when to stop everything and - # validate that at least one event is seen. - wait_app + 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 a788f8694..c95a4a1f9 100755 --- a/tests/regression/ust/buffers-pid/test_buffers_pid +++ b/tests/regression/ust/buffers-pid/test_buffers_pid @@ -58,14 +58,15 @@ test_after_multiple_apps() { start_lttng_tracing $SESSION_NAME 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 >/dev/null 2>&1 & ok $? "Start application $i for tracing" done + wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - trace_matches $EVENT_NAME $[NR_ITER * 5] $TRACE_PATH + trace_match_only $EVENT_NAME $[NR_ITER * 5] $TRACE_PATH return $? } @@ -73,11 +74,13 @@ 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 @@ -87,6 +90,10 @@ test_before_multiple_apps() { 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" @@ -94,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" @@ -119,37 +131,46 @@ test_after_app() { enable_ust_lttng_event $SESSION_NAME $EVENT_NAME "channel0" start_lttng_tracing $SESSION_NAME - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & ok $? "Start application to trace" + wait stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - trace_matches $EVENT_NAME $NR_ITER $TRACE_PATH + trace_match_only $EVENT_NAME $NR_ITER $TRACE_PATH return $? } 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" - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & - ok $? "Start application to trace" # 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" + + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT ${file_sync_after_first} ${file_sync_before_last} & + ok $? "Start application to trace" + start_lttng_tracing $SESSION_NAME - # At least hit one event - sleep 2 + 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" @@ -161,8 +182,6 @@ test_before_app() { out=0 fi - wait_apps - return $out } @@ -191,11 +210,12 @@ test_multiple_channels() { ok $? "Enable event $EVENT_NAME for session $SESSION_NAME in channel4" start_lttng_tracing $SESSION_NAME - $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT + $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT & ok $? "Start application to trace" + wait stop_lttng_tracing $SESSION_NAME - trace_matches $EVENT_NAME $[NR_ITER * 5] $TRACE_PATH + trace_match_only $EVENT_NAME $[NR_ITER * 5] $TRACE_PATH out=$? destroy_lttng_session $SESSION_NAME diff --git a/tests/regression/ust/high-throughput/test_high_throughput b/tests/regression/ust/high-throughput/test_high_throughput index 101a2c0a6..1ee0ec10f 100755 --- a/tests/regression/ust/high-throughput/test_high_throughput +++ b/tests/regression/ust/high-throughput/test_high_throughput @@ -46,7 +46,7 @@ enable_ust_lttng_event $SESSION_NAME $EVENT_NAME start_lttng_tracing $SESSION_NAME for i in `seq 1 $NR_APP`; do - ./$CURDIR/$BIN_NAME & >/dev/null 2>&1 + ./$CURDIR/$BIN_NAME >/dev/null 2>&1 & done diag "Waiting for applications to end" diff --git a/tests/regression/ust/java-jul/test_java_jul b/tests/regression/ust/java-jul/test_java_jul index 08214c0eb..a9dd235cc 100755 --- a/tests/regression/ust/java-jul/test_java_jul +++ b/tests/regression/ust/java-jul/test_java_jul @@ -78,6 +78,8 @@ function test_jul_before_start () # Run 5 times with a 1 second delay run_app + #FIXME: racy missing synchronization + start_lttng_tracing $SESSION_NAME # Wait for the applications started in background diff --git a/tests/regression/ust/multi-session/test_multi_session b/tests/regression/ust/multi-session/test_multi_session index 313a7d70f..e1ff9b091 100755 --- a/tests/regression/ust/multi-session/test_multi_session +++ b/tests/regression/ust/multi-session/test_multi_session @@ -44,11 +44,7 @@ test_multi_session() { ./$CURDIR/gen-nevents $NR_ITER & ok $? "Start application to generate $NR_ITER events" - # At least hit one event - while [ -n "$(pidof gen-nevents)" ]; do - sleep 0.1 - done - + wait pass "Wait for events to record" for i in `seq 0 3`; do diff --git a/tests/regression/ust/nprocesses/test_nprocesses b/tests/regression/ust/nprocesses/test_nprocesses index 396dab0d8..ca0f9d416 100755 --- a/tests/regression/ust/nprocesses/test_nprocesses +++ b/tests/regression/ust/nprocesses/test_nprocesses @@ -53,6 +53,8 @@ do APPS_PID="${APPS_PID} ${!}" done +#FIXME: racy missing synchronization + diag "Waiting for applications to be registered to sessiond" reg_app_count=0 @@ -76,6 +78,8 @@ start_lttng_tracing $SESSION_NAME stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME +#FIXME/TODO: add validation after fixing racy synchroniaation + rm -rf $TRACE_PATH diag "Stopping all spawned applications" @@ -83,6 +87,7 @@ for p in ${APPS_PID}; do kill ${p} wait ${p} 2>/dev/null done +APPS_PID= pass "Stopped all spawned applications" 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 e4199652b..53db813e1 100755 --- a/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush +++ b/tests/regression/ust/periodical-metadata-flush/test_periodical_metadata_flush @@ -28,6 +28,7 @@ EVENT_NAME="tp:tptest" BIN_NAME="gen-nevents" NUM_TESTS=38 APP_TMP_FILE="/tmp/lttng_test_ust.42.file" +APPS_PID= source $TESTDIR/utils/utils.sh @@ -106,7 +107,9 @@ function start_trace_app() { # Start application with a temporary file. $TESTAPP_BIN $NR_ITER $NR_USEC_WAIT $APP_TMP_FILE & - ok $? "Start application to trace" + ret=$? + APPS_PID="${APPS_PID} ${!}" + ok $ret "Start application to trace" } function start_check_trace_app() @@ -115,9 +118,20 @@ function start_check_trace_app() check_app_tmp_file } + +function wait_trace_apps() +{ + for p in ${APPS_PID}; do + wait ${p} 2>/dev/null + done + APPS_PID= +} + test_after_app_pid() { local out + APPS_PID= + diag "Start application AFTER tracing is started" create_lttng_session $SESSION_NAME $TRACE_PATH @@ -133,7 +147,9 @@ test_after_app_pid() { # Make sure the application does not generate any more data, # thus ensuring that we are not flushing a packet concurrently # with validate_trace. - killall -SIGSTOP -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGSTOP ${p} + done # Give time to the consumer to write inflight data. sleep 2 @@ -141,11 +157,14 @@ test_after_app_pid() { validate_trace out=$? - killall -SIGKILL -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGKILL ${p} + wait ${p} 2>/dev/null + done stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - wait + wait_trace_apps return $out } @@ -154,6 +173,8 @@ test_before_app_pid() { local out local tmp_file="/tmp/lttng_test_ust.42.file" + APPS_PID= + diag "Start application BEFORE tracing is started" start_trace_app @@ -172,7 +193,9 @@ test_before_app_pid() { # Make sure the application does not generate any more data, # thus ensuring that we are not flushing a packet concurrently # with validate_trace. - killall -SIGSTOP -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGSTOP ${p} + done # Give time to the consumer to write inflight data. sleep 2 @@ -180,11 +203,15 @@ test_before_app_pid() { validate_trace out=$? - killall -SIGKILL -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGKILL ${p} + wait ${p} 2>/dev/null + done + stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - wait + wait_trace_apps return $out } @@ -192,6 +219,8 @@ test_before_app_pid() { test_after_app_uid() { local out + APPS_PID= + diag "Start application AFTER tracing is started" create_lttng_session $SESSION_NAME $TRACE_PATH @@ -207,7 +236,10 @@ test_after_app_uid() { # Make sure the application does not generate any more data, # thus ensuring that we are not flushing a packet concurrently # with validate_trace. - killall -SIGSTOP -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGSTOP ${p} + done + # Give time to the consumer to write inflight data. sleep 2 @@ -215,11 +247,14 @@ test_after_app_uid() { validate_trace out=$? - killall -SIGKILL -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGKILL ${p} + wait ${p} 2>/dev/null + done stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - wait + wait_trace_apps return $out } @@ -227,6 +262,8 @@ test_after_app_uid() { test_before_app_uid() { local out + APPS_PID= + diag "Start application BEFORE tracing is started" # Start application before tracing @@ -245,7 +282,9 @@ test_before_app_uid() { # Make sure the application does not generate any more data, # thus ensuring that we are not flushing a packet concurrently # with validate_trace. - killall -SIGSTOP -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGSTOP ${p} + done # Give time to the consumer to write inflight data. sleep 2 @@ -253,11 +292,14 @@ test_before_app_uid() { validate_trace out=$? - killall -SIGKILL -q $TESTAPP_NAME + for p in ${APPS_PID}; do + kill -s SIGKILL ${p} + wait ${p} 2>/dev/null + done stop_lttng_tracing $SESSION_NAME destroy_lttng_session $SESSION_NAME - wait + wait_trace_apps return $out } -- 2.34.1