From 3c4c35827bdf49a2e148829672e6ff1a9c1b1bb8 Mon Sep 17 00:00:00 2001 From: Jonathan Rajotte Date: Mon, 23 Aug 2021 17:12:28 -0400 Subject: [PATCH] Fix: tests: app unregistering is not guaranteed by app lifetime MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Observed issue ============== The per-pid timer based rotation tests fail on a minimal ptest yocto image. The test suite report that the second archive is not empty as it expects. Note that the yocto/OE image is running under QEMU without KVM. Cause ===== Since the image is running under QEMU without KVM, the overall processing capability of the VM is quite limited. The test seems to assume that between the first and the second rotation the app will be unregistered by the time the second rotation is issued. Note that the observable lifetime of an app is not equal to the lttng-sessiond/consumerd app visibility since we deal with app unregistration via a polling mechanism. Note, that as far as I understand, this is a testing issue only. It is still relevant in the context of rotation to validate that the second rotation archive does NOT contain info for a "dead" app under per-pid configuration. Solution ======== Move the rotation timer operation after the app is registered and considered unregistered from the point of view of lttng-sessiond/lttng-consumerd. This should give us a more robust approach. Known drawbacks ========= None. References ========== Signed-off-by: Jonathan Rajotte Signed-off-by: Jérémie Galarneau Change-Id: Ie8c542d29ef8bdb325efc05de14e80b179c68754 --- tests/regression/tools/mi/test_mi | 20 ++--- .../regression/tools/relayd-grouping/test_ust | 2 +- .../tools/rotation/test_save_load_mi | 4 +- tests/regression/tools/rotation/test_ust | 85 +++++++++++++++++-- .../regression/tools/save-load/test_autoload | 6 +- tests/utils/utils.sh | 18 +++- 6 files changed, 111 insertions(+), 24 deletions(-) diff --git a/tests/regression/tools/mi/test_mi b/tests/regression/tools/mi/test_mi index e17cad130..f67313ee6 100755 --- a/tests/regression/tools/mi/test_mi +++ b/tests/regression/tools/mi/test_mi @@ -217,7 +217,7 @@ function test_list_sessions () done OUTPUT_DEST=$OUTPUT_DIR/$OUTPUT_FILE - list_lttng_with_opts + list_lttng_ok $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: list sessions xsd validation" @@ -248,7 +248,7 @@ function test_list_session_long_path () create_lttng_session_ok $session_name ${output_basedir} OUTPUT_DEST=${output_basedir}/$OUTPUT_FILE - list_lttng_with_opts + list_lttng_ok $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: list session with long path xsd validation" @@ -410,7 +410,7 @@ function test_list_channel () #Begin testing OUTPUT_DEST=$OUTPUT_DIR/$OUTPUT_FILE - list_lttng_with_opts "$session_name -c $channel_name" + list_lttng_ok "$session_name -c $channel_name" $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: list channel xsd validation" @@ -460,7 +460,7 @@ function test_list_domain () #Begin testing OUTPUT_DEST=$OUTPUT_DIR/$OUTPUT_FILE - list_lttng_with_opts "$session_name -d" + list_lttng_ok "$session_name -d" $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: list domain xsd validation" @@ -511,7 +511,7 @@ function test_list_session () #Begin testing OUTPUT_DEST=$OUTPUT_DIR/$OUTPUT_FILE - list_lttng_with_opts $session_name + list_lttng_ok $session_name $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: list session xsd validation" @@ -553,7 +553,7 @@ function test_list_ust_event () sleep 0.5 done - list_lttng_with_opts "-u -f" + list_lttng_ok "-u -f" touch ${file_sync_before_last} @@ -779,7 +779,7 @@ function test_track_untrack () ok $? "Mi test: track pid expecting 3 processes got $num" #Test the pid_tracker listing - list_lttng_with_opts $session_name + list_lttng_ok $session_name $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: session list with pid_tracker validate" @@ -806,7 +806,7 @@ function test_track_untrack () ok $? "Mi test: untrack pid expecting 2 process got $num" #Check pid_tracker listing - list_lttng_with_opts $session_name + list_lttng_ok $session_name $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: session list with pid_tracker validate" @@ -839,7 +839,7 @@ function test_track_untrack () #Test if pid_tracker is enabled as definied by pid_tracker #behavior. If all pid are untrack than the pid_tracker is still #enabled (pid_tracker node is present). - list_lttng_with_opts $session_name + list_lttng_ok $session_name $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: session list with pid_tracker validate" @@ -872,7 +872,7 @@ function test_track_untrack () #Test if pid_tracker is enabled as definied by pid_tracker #behavior. If all pid are untrack thant the pid_tracker is #disabled (node pid_tracker do not exist) - list_lttng_with_opts $session_name + list_lttng_ok $session_name $MI_VALIDATE $OUTPUT_DEST ok $? "Mi test: session list with pid_tracker validate" diff --git a/tests/regression/tools/relayd-grouping/test_ust b/tests/regression/tools/relayd-grouping/test_ust index eecf95207..592dbd90d 100755 --- a/tests/regression/tools/relayd-grouping/test_ust +++ b/tests/regression/tools/relayd-grouping/test_ust @@ -36,7 +36,7 @@ function get_auto_session_name () LTTNG_BIN="${lttng_bin} --mi xml" OUTPUT_DEST=$(mktemp --tmpdir "tmp.${FUNCNAME[0]}_output.XXXXXX") - list_lttng_with_opts + list_lttng_ok $MI_VALIDATE "$OUTPUT_DEST" ok $? "Valid lttng list XML" diff --git a/tests/regression/tools/rotation/test_save_load_mi b/tests/regression/tools/rotation/test_save_load_mi index a4dce0951..6a1f42101 100755 --- a/tests/regression/tools/rotation/test_save_load_mi +++ b/tests/regression/tools/rotation/test_save_load_mi @@ -57,7 +57,7 @@ function test_save_load_mi () ok $? "Found the right rotation size value in XML" # Check the output of lttng list with the 2 rotation parameters - list_lttng_with_opts $SESSION_NAME + list_lttng_ok $SESSION_NAME $MI_VALIDATE ${tmp_xml_output} ok $? "Valid lttng list XML" @@ -77,7 +77,7 @@ function test_save_load_mi () OUTPUT_DEST=${tmp_xml_output} # Check the output of lttng list with the 2 rotation parameters after the load - list_lttng_with_opts $SESSION_NAME + list_lttng_ok $SESSION_NAME $MI_VALIDATE ${tmp_xml_output} ok $? "Valid lttng list XML after load" diff --git a/tests/regression/tools/rotation/test_ust b/tests/regression/tools/rotation/test_ust index 278684d67..76c4ad579 100755 --- a/tests/regression/tools/rotation/test_ust +++ b/tests/regression/tools/rotation/test_ust @@ -17,7 +17,7 @@ EVENT_NAME="tp:tptest" TRACE_PATH=$(mktemp --tmpdir -d -t tmp.test_ust_rotation_trace_path.XXXXXX) -NUM_TESTS=136 +NUM_TESTS=138 source $TESTDIR/utils/utils.sh source $CURDIR/rotate_utils.sh @@ -26,6 +26,9 @@ if [ ! -x "$TESTAPP_BIN" ]; then BAIL_OUT "No UST events binary detected." fi +XPATH_CMD_OUTPUT="//lttng:command/lttng:output" +XPATH_PID="$XPATH_CMD_OUTPUT/lttng:domains/lttng:domain[./lttng:type = 'UST']/lttng:pids/lttng:pid/lttng:id" + function enable_channel_per_pid () { sess_name=$1 @@ -97,6 +100,36 @@ function test_ust_local_pid () rotate_ust_test "${TRACE_PATH}/archives" "ust/pid/*/" 1 } +function wait_until_app_unregistration () +{ + local pid=$1 + local mi_output + local value=1 + + mi_output=$(mktemp) + + while [ $value -ne 0 ]; do + # Extract from lttng list tracepoint the registered apps. + # This should give us enough guarantee since that if the app is not + # present it is unregistered from lttng-sessiond point of view. + LTTNG_BIN="lttng --mi xml" OUTPUT_DEST="$mi_output" list_lttng_notap -u + if ! $MI_VALIDATE "$mi_output"; then + return 1 + fi + + value=$("$MI_VALIDATE" "$mi_output" "$XPATH_PID" | wc -l) + if [ $value -ne 0 ]; then + diag "At least one app is still registred from lttng-sessiond point of view" + sleep 1 + else + # No app present on listing. + break; + fi + done + + return 0 +} + function test_ust_local_timer_uid () { diag "Test ust local with session rotation timer per-uid" @@ -125,14 +158,34 @@ function test_ust_streaming_timer_uid () function test_ust_local_timer_pid () { + local app_pid + diag "Test ust local with session rotation timer per-pid" create_lttng_session_ok $SESSION_NAME $TRACE_PATH enable_channel_per_pid $SESSION_NAME "channel0" enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME "channel0" - lttng_enable_rotation_timer_ok $SESSION_NAME 500ms start_lttng_tracing_ok $SESSION_NAME - # We just want the app to register, no event generated - $TESTAPP_BIN -i 0 -w 0 > /dev/null 2>&1 + + # We just want the app to register, no event generated. + # But we want the pid for the app since we need to validate its + # unregistration on lttng listing. + $TESTAPP_BIN -i 0 -w 0 > /dev/null 2>&1 & + app_pid=$! + wait $app_pid + + wait_until_app_unregistration $app_pid + ok $? "App is un-registered" + + # Set the rotation after that the app is done and that it was + # unregistered from lttng-sessiond. + # This is necessary since the rotate_timer_test function expects the + # second rotation archive to be empty. On slow machine it can take more + # than 500ms for the lttng-sessiond to receive and handle an app + # termination. This can lead to situation where the second rotation + # archive still have the channels for the pid for the app since that + # from the point of view of the lttng-sessiond/consumer the app is still + # "alive" and "kicking". This is a problem only for per-pid testing. + lttng_enable_rotation_timer_ok $SESSION_NAME 500ms rotate_timer_test "${TRACE_PATH}/archives" 1 } @@ -143,10 +196,28 @@ function test_ust_streaming_timer_pid () create_lttng_session_uri $SESSION_NAME net://localhost enable_channel_per_pid $SESSION_NAME "channel0" enable_ust_lttng_event_ok $SESSION_NAME $EVENT_NAME "channel0" - lttng_enable_rotation_timer_ok $SESSION_NAME 500ms start_lttng_tracing_ok $SESSION_NAME - # We just want the app to register, no event generated - $TESTAPP_BIN -i 0 -w 0 > /dev/null 2>&1 + + # We just want the app to register, no event generated. + # But we want the pid for the app since we need to validate its + # unregistration on lttng listing. + $TESTAPP_BIN -i 0 -w 0 > /dev/null 2>&1 & + app_pid=$! + wait $app_pid + + wait_until_app_unregistration $app_pid + ok $? "App is un-registered" + + # Set the rotation after that the app is done and that it was + # unregistered from lttng-sessiond. + # This is necessary since the rotate_timer_test function expects the + # second rotation archive to be empty. On slow machine it can take more + # than 500ms for the lttng-sessiond to receive and handle an app + # termination. This can lead to situation where the second rotation + # archive still have the channels for the pid for the app since that + # from the point of view of the lttng-sessiond/consumer the app is still + # "alive" and "kicking". This is a problem only for per-pid testing. + lttng_enable_rotation_timer_ok $SESSION_NAME 500ms rotate_timer_test "${TRACE_PATH}/${HOSTNAME}/${SESSION_NAME}*/archives" 1 } diff --git a/tests/regression/tools/save-load/test_autoload b/tests/regression/tools/save-load/test_autoload index 0fbfa49f1..b1134266a 100755 --- a/tests/regression/tools/save-load/test_autoload +++ b/tests/regression/tools/save-load/test_autoload @@ -27,7 +27,7 @@ function test_auto_load_file() diag "Test auto load file" start_lttng_sessiond $CURDIR/load-42.lttng - list_lttng_with_opts load-42 + list_lttng_ok load-42 stop_lttng_sessiond } @@ -38,7 +38,7 @@ function test_auto_load_dir() cp -f $CURDIR/load-42.lttng $LTTNG_DIR/ start_lttng_sessiond $LTTNG_DIR - list_lttng_with_opts load-42 + list_lttng_ok load-42 stop_lttng_sessiond } @@ -50,7 +50,7 @@ function test_auto_load_lttng_home() cp -f $CURDIR/load-42.lttng $LTTNG_HOME/.lttng/sessions/auto start_lttng_sessiond - list_lttng_with_opts load-42 + list_lttng_ok load-42 stop_lttng_sessiond } diff --git a/tests/utils/utils.sh b/tests/utils/utils.sh index c6d627cef..2680daae9 100644 --- a/tests/utils/utils.sh +++ b/tests/utils/utils.sh @@ -1028,10 +1028,26 @@ function sigstop_lttng_consumerd_notap() function list_lttng_with_opts () { + local ret + local withtap=$1 + shift local opts=$1 _run_lttng_cmd "$OUTPUT_DEST" "$ERROR_OUTPUT_DEST" \ list $opts - ok $? "Lttng-tool list command with option $opts" + ret=$? + if [ $withtap -eq "1" ]; then + ok $ret "Lttng-tool list command with option $opts" + fi +} + +function list_lttng_ok () +{ + list_lttng_with_opts 1 "$@" +} + +function list_lttng_notap () +{ + list_lttng_with_opts 0 "$@" } function create_lttng_session_no_output () -- 2.34.1