From d3392e4850532c02e53e3c3ff1cc27df7e51c941 Mon Sep 17 00:00:00 2001
|
From: Francis Deslauriers <francis.deslauriers@efficios.com>
|
Date: Tue, 7 Sep 2021 17:10:31 -0400
|
Subject: [PATCH 1/2] Fix: Tests: race condition in test_event_tracker
|
MIME-Version: 1.0
|
Content-Type: text/plain; charset=UTF-8
|
Content-Transfer-Encoding: 8bit
|
|
Background
|
==========
|
The `test_event_tracker` file contains test cases when the event
|
generating app in executed in two distinct steps. Those two steps are
|
preparation and execution.
|
1. the preparation is the launching the app in the background, and
|
2. the execution is actually generating the event that should or
|
should not be traced depending on the test case.
|
|
This is useful to test the tracker feature since we want to ensure that
|
already running apps are notified properly when changing their tracking
|
status.
|
|
Issue
|
=====
|
The `test_event_vpid_track_untrack` test case suffers from a race
|
condition that is easy to reproduce on Yocto.
|
|
The issue is that sometimes events are end up the trace when none is
|
expected.
|
|
This is due to the absence of synchronization point at the launch of the
|
app which leads to the app being scheduled in-between the track-untrack
|
calls leading to events being recorded to the trace.
|
|
It's easy to reproduce this issue on my machine by adding a `sleep 5`
|
between the track and untrack calls and setting the `NR_USEC_WAIT`
|
variable to 1.
|
|
Fix
|
===
|
Using the testapp `--sync-before-last-event-touch` flag to make the app
|
create a file when all but the last event are executed. We then have the
|
app wait until we create a file (`--sync-before-last-event`) to generate
|
that last event. This way, we are sure no event will be generated when
|
running the track and untrack commands.
|
|
Notes
|
=====
|
- This issue affects other test cases in this file.
|
- This commit fixes a typo in the test header.
|
- This commit adds `diag` calls to help tracking to what test the output
|
relates to when reading the log.
|
|
Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
|
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
|
Change-Id: Ia2b68128dc9a805526f9748f31ec2c2d95566f31
|
Upstream-Status: Backport
|
Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
|
---
|
.../tools/tracker/test_event_tracker | 56 ++++++++++++++-----
|
1 file changed, 42 insertions(+), 14 deletions(-)
|
|
diff --git a/tests/regression/tools/tracker/test_event_tracker b/tests/regression/tools/tracker/test_event_tracker
|
index feb3787..cc0f698 100755
|
--- a/tests/regression/tools/tracker/test_event_tracker
|
+++ b/tests/regression/tools/tracker/test_event_tracker
|
@@ -5,7 +5,7 @@
|
#
|
# SPDX-License-Identifier: GPL-2.0-only
|
|
-TEST_DESC="LTTng - Event traker test"
|
+TEST_DESC="LTTng - Event tracker test"
|
|
CURDIR=$(dirname "$0")/
|
TESTDIR="$CURDIR/../../.."
|
@@ -15,7 +15,7 @@ TESTAPP_KERNEL_NAME="gen-kernel-test-events"
|
TESTAPP_BIN="$TESTAPP_PATH/$TESTAPP_NAME/$TESTAPP_NAME"
|
TESTAPP_KERNEL_BIN="$TESTAPP_PATH/$TESTAPP_KERNEL_NAME/$TESTAPP_KERNEL_NAME"
|
SESSION_NAME="tracker"
|
-NR_ITER=100
|
+NR_ITER=1
|
NUM_GLOBAL_TESTS=2
|
NUM_UST_TESTS=283
|
NUM_KERNEL_TESTS=462
|
@@ -30,27 +30,41 @@ SCRIPT_GROUPNAME="$(id -gn)"
|
|
CHILD_PID=-1
|
WAIT_PATH=
|
-AFTER_FIRST_PATH=
|
-BEFORE_LAST_PATH=
|
+TOUCH_BEFORE_LAST_PATH=
|
+SYNC_BEFORE_LAST_PATH=
|
|
source $TESTDIR/utils/utils.sh
|
|
+# Launch the testapp and execute it up until right before the last event. It is
|
+# useful to do it in two seperate steps in order to test tracking and
|
+# untracking on an active app.
|
function prepare_ust_app
|
{
|
- AFTER_FIRST_PATH=$(mktemp --tmpdir -u tmp.${FUNCNAME[0]}_sync_after_first.XXXXXX)
|
- BEFORE_LAST_PATH=$(mktemp --tmpdir -u tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX)
|
+ TOUCH_BEFORE_LAST_PATH=$(mktemp --tmpdir -u tmp.${FUNCNAME[0]}_touch_before_last.XXXXXX)
|
+ SYNC_BEFORE_LAST_PATH=$(mktemp --tmpdir -u tmp.${FUNCNAME[0]}_sync_before_last.XXXXXX)
|
+
|
+ $TESTAPP_BIN -i $NR_ITER -w $NR_USEC_WAIT \
|
+ --sync-before-last-event-touch "$TOUCH_BEFORE_LAST_PATH" \
|
+ --sync-before-last-event "$SYNC_BEFORE_LAST_PATH" &
|
|
- $TESTAPP_BIN -i $NR_ITER -w $NR_USEC_WAIT -a "$AFTER_FIRST_PATH" -b "$BEFORE_LAST_PATH" &
|
CHILD_PID=$!
|
+
|
+ # Wait for the app to execute all the way to right before the last
|
+ # event.
|
+ while [ ! -f "${TOUCH_BEFORE_LAST_PATH}" ]; do
|
+ sleep 0.5
|
+ done
|
}
|
|
+# Generate the last event.
|
function trace_ust_app
|
{
|
- touch "$BEFORE_LAST_PATH"
|
- wait
|
+ # Ask the test app to generate the last event.
|
+ touch "$SYNC_BEFORE_LAST_PATH"
|
+ wait "$CHILD_PID"
|
ok $? "Traced application stopped."
|
- rm "$BEFORE_LAST_PATH"
|
- rm "$AFTER_FIRST_PATH"
|
+ rm "$SYNC_BEFORE_LAST_PATH"
|
+ rm "$TOUCH_BEFORE_LAST_PATH"
|
}
|
|
function prepare_kernel_app
|
@@ -64,7 +78,7 @@ function prepare_kernel_app
|
function trace_kernel_app
|
{
|
touch "$WAIT_PATH"
|
- wait
|
+ wait "$CHILD_PID"
|
ok $? "Traced application stopped."
|
rm "$WAIT_PATH"
|
}
|
@@ -78,6 +92,8 @@ function test_event_tracker()
|
local tracker="$4"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -117,6 +133,8 @@ function test_event_vpid_tracker()
|
local wildcard="$3"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -160,6 +178,8 @@ function test_event_pid_tracker()
|
local wildcard="$3"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -203,6 +223,8 @@ function test_event_tracker_fail()
|
local wildcard="$2"
|
local tracker="$3"
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -222,6 +244,8 @@ function test_event_track_untrack()
|
local tracker="$4"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -262,6 +286,8 @@ function test_event_vpid_track_untrack()
|
local wildcard="$3"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -302,6 +328,8 @@ function test_event_pid_track_untrack()
|
local wildcard="$3"
|
local channel=''
|
|
+ diag "${FUNCNAME[0]} $*"
|
+
|
trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path"
|
@@ -336,9 +364,9 @@ function test_event_pid_track_untrack()
|
|
function test_event_ust_vpid_untrack_snapshot()
|
{
|
- local trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
+ diag "${FUNCNAME[0]} $*"
|
|
- diag "Test_event_ust_vpid_untrack_snapshot"
|
+ local trace_path=$(mktemp --tmpdir -d tmp.${FUNCNAME[0]}_trace_path.XXXXXX)
|
|
create_lttng_session_ok $SESSION_NAME "$trace_path" "--snapshot"
|
|
--
|
2.20.1
|