[lttng-dev] [PATCH lttng-tools v2] Fix: add missing synchronization point for before app test case
Jérémie Galarneau
jeremie.galarneau at efficios.com
Wed Nov 26 15:20:28 EST 2014
All merged, thanks!
Jérémie
On Thu, Nov 20, 2014 at 1:40 AM, Mathieu Desnoyers
<mathieu.desnoyers at efficios.com> wrote:
> Fixes a race where the application could generate all its events before
> trace start.
>
> Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers at efficios.com>
> ---
> .../regression/tools/snapshots/test_ust_streaming | 2 +-
> tests/regression/tools/snapshots/ust_test | 2 +-
> tests/regression/tools/streaming/test_ust | 21 ++++++--
> .../regression/ust/before-after/test_before_after | 11 ++--
> tests/regression/ust/buffers-pid/test_buffers_pid | 26 ++++++---
> tests/regression/ust/java-jul/test_java_jul | 11 +++-
> tests/regression/ust/java-log4j/test_java_log4j | 11 +++-
> tests/regression/ust/nprocesses/test_nprocesses | 14 +++--
> .../test_periodical_metadata_flush | 2 +-
> .../utils/testapp/gen-ust-events/gen-ust-events.c | 63 +++++++++++++++++-----
> 10 files changed, 126 insertions(+), 37 deletions(-)
>
> diff --git a/tests/regression/tools/snapshots/test_ust_streaming b/tests/regression/tools/snapshots/test_ust_streaming
> index 55c1087..ef38bd5 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 1541e6e..cbc2058 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 4807175..e6a0bb8 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 1535f36..460b04c 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 0258e89..c95a4a1 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 d16880f..d32d9ed 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 11845a0..a0b7cdc 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 ca0f9d4..8eed95f 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 53db813..7937fa2 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
> diff --git a/tests/utils/testapp/gen-ust-events/gen-ust-events.c b/tests/utils/testapp/gen-ust-events/gen-ust-events.c
> index 42fa082..5fb2683 100644
> --- a/tests/utils/testapp/gen-ust-events/gen-ust-events.c
> +++ b/tests/utils/testapp/gen-ust-events/gen-ust-events.c
> @@ -15,6 +15,7 @@
> * Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
> */
>
> +#define _GNU_SOURCE
> #include <assert.h>
> #include <arpa/inet.h>
> #include <fcntl.h>
> @@ -27,15 +28,21 @@
> #include <sys/types.h>
> #include <unistd.h>
> #include <stdbool.h>
> +#include <signal.h>
> +#include <poll.h>
> +#include <errno.h>
>
> #define TRACEPOINT_DEFINE
> #include "tp.h"
>
> void create_file(const char *path)
> {
> + static bool file_created = false;
> int ret;
>
> - assert(path);
> + if (!path || file_created) {
> + return;
> + }
>
> ret = creat(path, S_IRWXU);
> if (ret < 0) {
> @@ -44,6 +51,30 @@ void create_file(const char *path)
> }
>
> (void) close(ret);
> + file_created = true;
> +}
> +
> +static
> +void wait_on_file(const char *path)
> +{
> + if (!path) {
> + return;
> + }
> + for (;;) {
> + int ret;
> + struct stat buf;
> +
> + ret = stat(path, &buf);
> + if (ret == -1 && errno == ENOENT) {
> + (void) poll(NULL, 0, 10); /* 10 ms delay */
> + continue; /* retry */
> + }
> + if (ret) {
> + perror("stat");
> + exit(EXIT_FAILURE);
> + }
> + break; /* found */
> + }
> }
>
> int main(int argc, char **argv)
> @@ -55,8 +86,8 @@ int main(int argc, char **argv)
> float flt = 2222.0;
> int nr_iter = 100;
> useconds_t nr_usec = 0;
> - char *tmp_file_path = NULL;
> - bool file_created = false;
> + char *after_first_event_file_path = NULL;
> + char *before_last_event_file_path = NULL;
>
> if (argc >= 2) {
> /*
> @@ -71,22 +102,30 @@ int main(int argc, char **argv)
> }
>
> if (argc >= 4) {
> - tmp_file_path = argv[3];
> + after_first_event_file_path = argv[3];
> + }
> +
> + if (argc >= 5) {
> + before_last_event_file_path = argv[4];
> }
>
> for (i = 0; nr_iter < 0 || i < nr_iter; i++) {
> + if (nr_iter >= 0 && i == nr_iter - 1) {
> + /*
> + * Wait on synchronization before writing last
> + * event.
> + */
> + wait_on_file(before_last_event_file_path);
> + }
> netint = htonl(i);
> - tracepoint(tp, tptest, i, netint, values, text, strlen(text), dbl,
> - flt);
> + tracepoint(tp, tptest, i, netint, values, text,
> + strlen(text), dbl, flt);
>
> /*
> - * First loop we create the file if asked to indicate that at least one
> - * tracepoint has been hit.
> + * First loop we create the file if asked to indicate
> + * that at least one tracepoint has been hit.
> */
> - if (!file_created && tmp_file_path) {
> - create_file(tmp_file_path);
> - file_created = true;
> - }
> + create_file(after_first_event_file_path);
> usleep(nr_usec);
> }
>
> --
> 2.1.1
>
--
Jérémie Galarneau
EfficiOS Inc.
http://www.efficios.com
More information about the lttng-dev
mailing list