[fx][metrics] fix flaky test
metrics test was using a sleep to account for the background metrics
collection started by fx. This CL changes it to call the metrics methods
directly, instead of calling them via fx.
In addition, this CL also fix a technical debt that the metrics
debugging file was being saved to a hardcoded file in /tmp, potentially
causing issues with multiple source trees debugging metrics calls.
Fixed: 54628
Change-Id: Ie437a4a33a3a74592a6c099d2ab809221354535e
Reviewed-on: https://fuchsia-review.googlesource.com/c/fuchsia/+/405079
Testability-Review: Renato Mangini Dias <mangini@google.com>
Reviewed-by: Jonathan Koren <jdkoren@google.com>
Reviewed-by: Wesley Moy <wesleymoy@google.com>
Commit-Queue: Renato Mangini Dias <mangini@google.com>
diff --git a/tools/devshell/lib/metrics.sh b/tools/devshell/lib/metrics.sh
index 2a0f0ba..43f5ccb 100755
--- a/tools/devshell/lib/metrics.sh
+++ b/tools/devshell/lib/metrics.sh
@@ -7,11 +7,18 @@
### this script assumes that vars.sh has already been sourced, since it
### depends on FUCHSIA_DIR being defined correctly.
-declare -r GA_PROPERTY_ID="UA-127897021-6"
-declare -r TRACK_ALL_ARGS=( "set" "fidlcat" "run-test" "run-test-component" "run-host-tests" )
-declare -r TRACK_RESULTS=( "set" "build" )
-declare -r ALLOWS_CUSTOM_REPORTING=( "test" )
-declare -r DEBUG_LOG_CONFIG="/tmp/.fx_metrics_debugfile"
+_METRICS_GA_PROPERTY_ID="UA-127897021-6"
+_METRICS_TRACK_ALL_ARGS=( "set" "fidlcat" "run-test" "run-test-component" "run-host-tests" )
+_METRICS_TRACK_RESULTS=( "set" "build" )
+_METRICS_ALLOWS_CUSTOM_REPORTING=( "test" )
+
+# These variables need to be global, but readonly (or declare -r) declares new
+# variables as local when they are source'd inside a function.
+# "declare -g -r" is the right way to handle it, but it is not supported in
+# old versions of Bash, particularly in the one in MacOS. The alternative is to
+# make them global first via the assignments above and marking they readonly
+# later.
+readonly _METRICS_GA_PROPERTY_ID _METRICS_TRACK_ALL_ARGS _METRICS_TRACK_RESULTS _METRICS_ALLOWS_CUSTOM_REPORTING
# To properly enable unit testing, METRICS_CONFIG is not read-only
METRICS_CONFIG="${FUCHSIA_DIR}/.fx-metrics-config"
@@ -47,6 +54,7 @@
function metrics-read-config {
METRICS_UUID=""
METRICS_ENABLED=0
+ _METRICS_DEBUG_LOG_FILE=""
if [[ ! -f "${METRICS_CONFIG}" ]]; then
return 1
fi
@@ -59,9 +67,12 @@
}
function metrics-write-config {
- enabled=$1
+ local enabled=$1
if [[ "$enabled" -eq "1" ]]; then
- uuid="$2"
+ local uuid="$2"
+ if [[ $# -gt 2 ]]; then
+ local debug_logfile="$3"
+ fi
fi
local -r tempfile="$(mktemp)"
@@ -72,6 +83,9 @@
echo "# Autogenerated config file for fx metrics. Run 'fx help metrics' for more information."
echo "METRICS_ENABLED=${enabled}"
echo "METRICS_UUID=\"${uuid}\""
+ if [[ -n "${debug_logfile}" ]]; then
+ echo "_METRICS_DEBUG_LOG_FILE=${debug_logfile}"
+ fi
} >> "${tempfile}"
# Only rewrite the config file if content has changed
if ! cmp --silent "${tempfile}" "${METRICS_CONFIG}" ; then
@@ -91,32 +105,19 @@
}
function metrics-set-debug-logfile {
- debug_logfile="$1"
- # make sure that either DEBUG_LOG_CONFIG is writable or it doesn't exist
- # and its directory is writable
- if [[ -w "${DEBUG_LOG_CONFIG}" || \
- ( ! -f "${DEBUG_LOG_CONFIG}" &&
- -w "$(dirname "${DEBUG_LOG_CONFIG}")" ) ]]; then
- echo "$debug_logfile" > "$DEBUG_LOG_CONFIG"
- return 0
- else
- fx-warn "Cannot persist the metrics log filename to ${DEBUG_LOG_CONFIG}"
- fx-warn "Ignoring debug logging of metrics collection"
- fi
- return 1
+ _METRICS_DEBUG_LOG_FILE="$1"
+ return 0
}
function metrics-get-debug-logfile {
- if [[ $_METRICS_DEBUG == 1 ]]; then
+ if [[ -n "$_METRICS_DEBUG_LOG_FILE" ]]; then
echo "$_METRICS_DEBUG_LOG_FILE"
- elif [[ -f "$DEBUG_LOG_CONFIG" ]]; then
- head -1 "$DEBUG_LOG_CONFIG"
fi
}
function metrics-maybe-log {
local filename="$(metrics-get-debug-logfile)"
- if [[ $filename ]]; then
+ if [[ -n "$filename" ]]; then
if [[ ! -f "$filename" && -w $(dirname "$filename") ]]; then
touch "$filename"
fi
@@ -146,8 +147,8 @@
shift 2
local event_label="$*"
- # Only allow custom arguments to subcommands defined in # $ALLOWS_CUSTOM_REPORTING
- if ! __is_in "$subcommand" "${ALLOWS_CUSTOM_REPORTING[@]}"; then
+ # Only allow custom arguments to subcommands defined in # $_METRICS_ALLOWS_CUSTOM_REPORTING
+ if ! __is_in "$subcommand" "${_METRICS_ALLOWS_CUSTOM_REPORTING[@]}"; then
return 1
fi
@@ -180,9 +181,9 @@
# - the name of the fx subcommand
# - args of the subcommand
function track-command-execution {
- subcommand="$1"
+ local subcommand="$1"
shift
- args="$*"
+ local args="$*"
local hide_init_warning=0
if [[ "$subcommand" == "metrics" ]]; then
@@ -198,8 +199,8 @@
_process-fx-set-command "$@"
fi
- # Only track arguments to the subcommands in $TRACK_ALL_ARGS
- if ! __is_in "$subcommand" "${TRACK_ALL_ARGS[@]}"; then
+ # Only track arguments to the subcommands in $_METRICS_TRACK_ALL_ARGS
+ if ! __is_in "$subcommand" "${_METRICS_TRACK_ALL_ARGS[@]}"; then
args=""
else
# Limit to the first 100 characters of arguments.
@@ -225,7 +226,7 @@
# Arguments:
# - args of `fx set`
function _process-fx-set-command {
- target="$1"
+ local target="$1"
shift
while [[ $# -ne 0 ]]; do
case $1 in
@@ -279,12 +280,12 @@
args="$*"
metrics-read-config
- if [[ $METRICS_ENABLED == 0 ]] || ! __is_in "$subcommand" "${TRACK_RESULTS[@]}"; then
+ if [[ $METRICS_ENABLED == 0 ]] || ! __is_in "$subcommand" "${_METRICS_TRACK_RESULTS[@]}"; then
return 0
fi
- # Only track arguments to the subcommands in $TRACK_ALL_ARGS
- if ! __is_in "$subcommand" "${TRACK_ALL_ARGS[@]}"; then
+ # Only track arguments to the subcommands in $_METRICS_TRACK_ALL_ARGS
+ if ! __is_in "$subcommand" "${_METRICS_TRACK_ALL_ARGS[@]}"; then
args=""
else
# Limit to the first 100 characters of arguments.
@@ -346,7 +347,7 @@
local app_version="$(_app_version)"
params=(
"v=1" \
- "tid=${GA_PROPERTY_ID}" \
+ "tid=${_METRICS_GA_PROPERTY_ID}" \
"cid=${METRICS_UUID}" \
"an=${app_name}" \
"av=${app_version}" \
diff --git a/tools/devshell/metrics b/tools/devshell/metrics
index 3dd7f0b..667d5e4 100755
--- a/tools/devshell/metrics
+++ b/tools/devshell/metrics
@@ -48,14 +48,14 @@
- (in the future) Imports in BUILDDIR/args.gn for product and board
- (in the future) Value FUCHSIA_ARCH from BUILDDIR/fx.config
-2. For the following subcomand(s) [${TRACK_ALL_ARGS}]:
+2. For the subcomand(s) [${_METRICS_TRACK_ALL_ARGS[@]}]:
- All arguments passed to the subcommand
-3. For the following subcomand(s) [${TRACK_RESULTS}]:
+3. For the subcomand(s) [${_METRICS_TRACK_RESULTS[@]}]:
- Time taken to complete
- Exit status
-4. Custom events for the following subcommand(s): [${ALLOWS_CUSTOM_REPORTING}]
+4. Custom events for the subcommand(s): [${_METRICS_ALLOWS_CUSTOM_REPORTING[@]}]
When metrics collection is disabled, any existing UUID is deleted, and a
new UUID will be created if metrics is later re-enabled.
@@ -122,20 +122,20 @@
shift
done
+# Read config in a way that exit code is preserved but doesn't exit because
+# of "set -e" if config file doesn't exist
+__successfully_read_config=0
+metrics-read-config || __successfully_read_config=$?
+
if [[ "$has_debug_logfile" -eq 1 ]]; then
if [[ $action != "enable" ]]; then
fx-error "Invalid syntax, you can only specify --log when enabling metrics"
fx-command-help
exit 1
fi
- metrics-set-debug-logfile "$debug_logfile"
+ metrics-set-debug-logfile "${debug_logfile}"
fi
-# Read config in a way that exit code is preserved but doesn't exit because
-# of "set -e" if config file doesn't exist
-__successfully_read_config=0
-metrics-read-config || __successfully_read_config=$?
-
if [[ $action == "status" ]]; then
echo "Collection of metrics is currently $(styled-status "$METRICS_ENABLED") for ${FUCHSIA_DIR}"
maybe-print-metrics-logfile-status
@@ -178,6 +178,6 @@
metrics-maybe-log "Metrics collection disabled at user's request"
fi
-metrics-write-config "${METRICS_ENABLED}" "${METRICS_UUID}"
+metrics-write-config "${METRICS_ENABLED}" "${METRICS_UUID}" "${debug_logfile}"
echo "Collection of metrics is now $(styled-status $METRICS_ENABLED) for ${FUCHSIA_DIR}"
diff --git a/tools/devshell/tests/fx-internal/metrics_test b/tools/devshell/tests/fx-internal/metrics_test
index dab1109..478424a 100644
--- a/tools/devshell/tests/fx-internal/metrics_test
+++ b/tools/devshell/tests/fx-internal/metrics_test
@@ -40,7 +40,11 @@
btf::add_binary_to_path "${mycurl}"
metrics_log="${BT_TEMP_DIR}/metrics_log"
BT_ASSERT_FILE_DOES_NOT_EXIST "${BT_TEMP_DIR}/.fx-metrics-config"
- ${fx} metrics enable "--log=${metrics_log}" > /dev/null
+
+ source "${BT_TEMP_DIR}/tools/devshell/lib/vars.sh"
+ source "${BT_TEMP_DIR}/tools/devshell/lib/metrics.sh"
+ metrics-write-config 1 TESTUUID "${metrics_log}"
+ metrics-read-config
}
verify_execution_event() {
@@ -65,8 +69,8 @@
TEST_metrics_doesnt_match_cmd_substring() {
local cmd="fidl"
local arg="someargs"
- ${fx} ${cmd} "${arg}"
- sleep 0.1 # sleep is required because metrics are collected as background jobs
+ track-command-execution "${cmd}" "$arg"
+ track-command-finished "200" "0" "${cmd}" "$arg"
verify_execution_event ${cmd}
# verify that the "fidl" command doesn't trigger the all args tracking that
@@ -83,9 +87,9 @@
TEST_metrics_no_arguments_tracking() {
local cmd="build"
local arg="something"
- ${fx} ${cmd} "${arg}"
- sleep 0.1 # sleep is required because metrics are collected as background jobs
- verify_execution_event ${cmd}
+ track-command-execution "${cmd}" "$arg"
+ track-command-finished "200" "0" "${cmd}" "$arg"
+ verify_execution_event "${cmd}"
# the "build" command does not track arguments:
for f in "${mycurl}".mock_state*; do
if btf::does-mock-args-contain "${f}" "--data-urlencode" "el=${arg}"; then
@@ -99,10 +103,10 @@
TEST_metrics_track_arguments() {
local cmd="set"
local arg="some argument"
- ${fx} ${cmd} "${arg}"
- # The "set" command tracks all arguments, let's verify:
- sleep 0.1 # sleep is required because metrics are collected as background jobs
+ track-command-execution "${cmd}" "$arg"
+ track-command-finished "200" "0" "${cmd}" "$arg"
verify_execution_event ${cmd}
+ # The "set" command tracks all arguments, let's verify:
BT_EXPECT_FILE_CONTAINS_SUBSTRING "${metrics_log}" "el=${arg}"
for f in "${mycurl}".mock_state*; do
if btf::does-mock-args-contain "${f}" "--data-urlencode" "el=${arg}"; then
@@ -118,13 +122,9 @@
local action="myaction"
local label="mylabel"
- cat > "${BT_TEMP_DIR}/tools/devshell/${cmd}.mock_side_effects" <<EOF
-source "\${FUCHSIA_DIR}/tools/devshell/lib/metrics.sh" || exit $?
-track-subcommand-custom-event "${cmd}" "${action}" "${label}"
-EOF
- ${fx} ${cmd}
- # The "set" command tracks all arguments, let's verify:
- sleep 0.1 # sleep is required because metrics are collected as background jobs
+ track-command-execution "${cmd}" "$arg"
+ track-subcommand-custom-event "${cmd}" "${action}" "${label}"
+ track-command-finished "200" "0" "${cmd}" "$arg"
verify_execution_event ${cmd}
for f in "${mycurl}".mock_state*; do
if btf::does-mock-args-contain "${f}" "--data-urlencode" "ec=fx_custom_${cmd}"; then
@@ -140,13 +140,9 @@
local action="myaction"
local label="mylabel"
- cat > "${BT_TEMP_DIR}/tools/devshell/${cmd}.mock_side_effects" <<EOF
-source "\${FUCHSIA_DIR}/tools/devshell/lib/metrics.sh" || exit $?
-track-subcommand-custom-event "${cmd}" "${action}" "${label}"
-EOF
- ${fx} ${cmd}
- # The "set" command tracks all arguments, let's verify:
- sleep 0.1 # sleep is required because metrics are collected as background jobs
+ track-command-execution "${cmd}" "$arg"
+ track-subcommand-custom-event "${cmd}" "${action}" "${label}"
+ track-command-finished "200" "0" "${cmd}" "$arg"
verify_execution_event ${cmd}
for f in "${mycurl}".mock_state*; do
if btf::does-mock-args-contain "${f}" "--data-urlencode" "ec=fx_custom_${cmd}"; then
