Add timing measurement of individual tests and report them

This commit is contained in:
Michael Boelen 2019-07-12 14:20:32 +02:00
parent 7506fd4af8
commit c31c6a5a9e
No known key found for this signature in database
GPG Key ID: 26141F77A09D7F04
2 changed files with 49 additions and 0 deletions

View File

@ -86,6 +86,7 @@ unset LANG
CONTAINER_TYPE=""
CREATE_REPORT_FILE=1
CSUMBINARY=""
CURRENT_TS=0
CUSTOM_URL_APPEND=""
CUSTOM_URL_PREPEND=""
CUSTOM_URL_PROTOCOL=""
@ -216,6 +217,8 @@ unset LANG
PLUGIN_PHASE=0
POSTFIXBINARY=""
POSTGRES_RUNNING=0
PREVIOUS_TEST="No test ID"
PREVIOUS_TS=0
PRIVILEGED=0
PROFILES=""
PROFILEVALUE=""

View File

@ -2187,6 +2187,19 @@
# Returns : SKIPTEST (0 or 1)
################################################################################
GetTimestamp() {
ts=0
case "${OS}" in
"Linux")
ts=$(date "+%s%N")
;;
*)
ts=$(date "+%s")
;;
esac
echo $ts
}
Register() {
# Do not insert a log break, if previous test was not logged
if [ ${SKIPLOGTEST} -eq 0 ]; then LogTextBreak; fi
@ -2254,6 +2267,35 @@
shift
done
# Measure timing
CURRENT_TS=$(GetTimestamp)
if [ ${PREVIOUS_TS} -gt 0 ]; then
SLOW_TEST=0
TIME_THRESHOLD=10 # seconds
# Calculate timing and determine if we use seconds or nanoseconds (more precise)
TIME_DIFF=$((${CURRENT_TS} - ${PREVIOUS_TS}))
if [ ${CURRENT_TS} -gt 1000000000000000000 ]; then
TIME_DIFF_FORMAT="nanoseconds"
TIME_THRESHOLD=$((${TIME_THRESHOLD} * 1000000000))
if [ ${TIME_DIFF} -gt ${TIME_THRESHOLD} ]; then
SLOW_TEST=1
# Convert back to seconds for readability
TIME_DIFF_FORMAT="seconds"
TIME_DIFF=$(echo ${TIME_DIFF} | ${AWKBINARY} '{printf "%f",$1/1000000000}')
fi
else
TIME_DIFF_FORMAT="seconds"
if [ ${TIME_DIFF} -gt ${TIME_THRESHOLD} ]; then
SLOW_TEST=1
fi
fi
if [ ${SLOW_TEST} -eq 1 ]; then
DisplayWarning "Test ${PREVIOUS_TEST} had a long execution: ${TIME_DIFF} ${TIME_DIFF_FORMAT}"
Report "slow_test[]=${PREVIOUS_TEST},${TIME_DIFF}"
fi
fi
# Skip test if it's configured in profile (old style)
if [ ${SKIPTEST} -eq 0 ]; then
FIND=$(echo "${TEST_SKIP_ALWAYS}" | grep "${TEST_NO}" | tr '[:lower:]' '[:upper:]')
@ -2326,6 +2368,10 @@
TESTS_SKIPPED="${TEST_NO}|${TESTS_SKIPPED}"
fi
unset SKIPREASON
# Save timestamp for next time the Register function is called
PREVIOUS_TEST="${TEST_NO}"
PREVIOUS_TS="${CURRENT_TS}"
}