michaelh/zephyr
1
0
Fork 0
Code Releases Activity

tests: ztest: provide test execution times per ztest testcase

Browse source 
Add execution time for testing result of each ztest testcase as:

START - test_sem_multi_take_timeout_diff_sem
PASS - test_sem_multi_take_timeout_diff_sem in 2.54 seconds

Fix #32137.

Signed-off-by: Enjia Mai <enjiax.mai@intel.com>
This commit is contained in:
Enjia Mai 2021-03-07 14:08:31 +08:00 • committed by Anas Nashif
commit 2c5e2c2394
2 changed files with 35 additions and 7 deletions
Download patch file Download diff file Expand all files Collapse all files

2
scripts/pylib/twister/harness.py
View file

@ -2,7 +2,7 @@
import re import re
from collections import OrderedDict from collections import OrderedDict
result_re = re.compile(".*(PASS|FAIL|SKIP) - (test_)?(.*)") result_re = re.compile(".*(PASS|FAIL|SKIP) - (test_)?(.*) in")
class Harness: class Harness:
GCOV_START = "GCOV_COVERAGE_DUMP_START" GCOV_START = "GCOV_COVERAGE_DUMP_START"

40
subsys/testsuite/include/tc_util.h
View file

@ -92,6 +92,27 @@ static inline const char *TC_RESULT_TO_STR(int result)
} }
} }
static uint32_t tc_start_time;
static uint32_t tc_spend_time;
static inline void get_start_time_cyc(void)
{
/* Besides the ztest framework, some testcase will also call
* TC_START() in their code. But the caller thread cannot be
* in userspace.
*/
if (!_is_user_context()) {
tc_start_time = k_cycle_get_32();
}
}
static inline void test_time_ms(void)
{
uint32_t spend_cycle = k_cycle_get_32() - tc_start_time;
tc_spend_time = k_cyc_to_ms_ceil32(spend_cycle);
}
#ifndef TC_ERROR #ifndef TC_ERROR
#define TC_ERROR(fmt, ...) \ #define TC_ERROR(fmt, ...) \
do { \ do { \
@ -105,7 +126,11 @@ static inline const char *TC_RESULT_TO_STR(int result)
#endif #endif
#ifndef TC_START #ifndef TC_START
#define TC_START(name) PRINT_DATA("START - %s\n", name) #define TC_START(name) \
do { \
PRINT_DATA("START - %s\n", name); \
get_start_time_cyc(); \
} while (0)
#endif #endif
#ifndef TC_END #ifndef TC_END
@ -114,10 +139,13 @@ static inline const char *TC_RESULT_TO_STR(int result)
#ifndef Z_TC_END_RESULT #ifndef Z_TC_END_RESULT
/* prints result and the function name */ /* prints result and the function name */
#define Z_TC_END_RESULT(result, func) \ #define Z_TC_END_RESULT(result, func) \
do { \ do { \
TC_END(result, " %s - %s\n", TC_RESULT_TO_STR(result), func); \ test_time_ms(); \
PRINT_LINE; \ TC_END(result, " %s - %s in %u.%u seconds\n", \
TC_RESULT_TO_STR(result), func, tc_spend_time/1000, \
tc_spend_time%1000); \
PRINT_LINE; \
} while (0) } while (0)
#endif #endif
@ -157,7 +185,7 @@ static inline const char *TC_RESULT_TO_STR(int result)
#define TC_CMD_ITEM(name) cmd_##name #define TC_CMD_ITEM(name) cmd_##name
#else #else
#define TC_CMD_DEFINE(name) \ #define TC_CMD_DEFINE(name) \
int cmd_##name(int argc, char *argv[]) \ int cmd_##name(int argc, char *argv[]) \
{ \ { \
TC_START(__func__); \ TC_START(__func__); \
name(); \ name(); \