diff --git a/frameworks/utest/source/default_handlers.cpp b/frameworks/utest/source/default_handlers.cpp index 44c0ffae42..4b19c35f04 100644 --- a/frameworks/utest/source/default_handlers.cpp +++ b/frameworks/utest/source/default_handlers.cpp @@ -18,6 +18,8 @@ #include "utest/default_handlers.h" #include "utest/case.h" +#include "utest/stack_trace.h" + using namespace utest::v1; @@ -35,6 +37,7 @@ const handlers_t utest::v1::verbose_continue_handlers = { // --- SPECIAL HANDLERS --- static void test_failure_handler(const failure_t failure) { + UTEST_LOG_FUNCTION if (failure.location == LOCATION_TEST_SETUP || failure.location == LOCATION_TEST_TEARDOWN) { verbose_test_failure_handler(failure); printf("{{failure}}\n{{end}}\n"); @@ -45,12 +48,14 @@ static void test_failure_handler(const failure_t failure) { // --- VERBOSE TEST HANDLERS --- status_t utest::v1::verbose_test_setup_handler(const size_t number_of_cases) { + UTEST_LOG_FUNCTION printf(">>> Running %u test cases...\n", number_of_cases); return STATUS_CONTINUE; } void utest::v1::verbose_test_teardown_handler(const size_t passed, const size_t failed, const failure_t failure) { + UTEST_LOG_FUNCTION printf("\n>>> Test cases: %u passed, %u failed", passed, failed); if (failure.reason == REASON_NONE) { printf("\n"); @@ -63,17 +68,20 @@ void utest::v1::verbose_test_teardown_handler(const size_t passed, const size_t void utest::v1::verbose_test_failure_handler(const failure_t failure) { printf(">>> failure with reason '%s' during '%s'\n", stringify(failure.reason), stringify(failure.location)); + } // --- VERBOSE CASE HANDLERS --- status_t utest::v1::verbose_case_setup_handler(const Case *const source, const size_t index_of_case) { + UTEST_LOG_FUNCTION printf("\n>>> Running case #%u: '%s'...\n", index_of_case + 1, source->get_description()); return STATUS_CONTINUE; } status_t utest::v1::verbose_case_teardown_handler(const Case *const source, const size_t passed, const size_t failed, const failure_t failure) { + UTEST_LOG_FUNCTION printf(">>> '%s': %u passed, %u failed", source->get_description(), passed, failed); if (failure.reason == REASON_NONE) { printf("\n"); @@ -85,6 +93,7 @@ status_t utest::v1::verbose_case_teardown_handler(const Case *const source, cons status_t utest::v1::verbose_case_failure_handler(const Case *const /*source*/, const failure_t failure) { + UTEST_LOG_FUNCTION if (!(failure.reason & REASON_ASSERTION)) { verbose_test_failure_handler(failure); } diff --git a/frameworks/utest/source/greentea_handlers.cpp b/frameworks/utest/source/greentea_handlers.cpp index e4760287e0..dc7fc610a9 100644 --- a/frameworks/utest/source/greentea_handlers.cpp +++ b/frameworks/utest/source/greentea_handlers.cpp @@ -19,6 +19,7 @@ #include "utest/default_handlers.h" #include "utest/case.h" #include "greentea-client/test_env.h" +#include "utest/stack_trace.h" using namespace utest::v1; @@ -57,6 +58,7 @@ const handlers_t utest::v1::selftest_handlers = { // --- SPECIAL HANDLERS --- static status_t unknown_test_setup_handler(const size_t) { + UTEST_LOG_FUNCTION printf(">>> I do not know how to tell greentea that the test started, since\n"); printf(">>> you forgot to override the `test_setup_handler` in your specification.\n"); @@ -64,16 +66,19 @@ static status_t unknown_test_setup_handler(const size_t) { } static void selftest_failure_handler(const failure_t failure) { + UTEST_LOG_FUNCTION if (failure.location == LOCATION_TEST_SETUP || failure.location == LOCATION_TEST_TEARDOWN || failure.reason == REASON_ASSERTION) { verbose_test_failure_handler(failure); } if (failure.reason == REASON_ASSERTION) { + UTEST_DUMP_TRACE GREENTEA_TESTSUITE_RESULT(false); while(1) ; } } static void test_failure_handler(const failure_t failure) { + UTEST_LOG_FUNCTION if (failure.location == LOCATION_TEST_SETUP || failure.location == LOCATION_TEST_TEARDOWN) { verbose_test_failure_handler(failure); GREENTEA_TESTSUITE_RESULT(false); @@ -84,12 +89,14 @@ static void test_failure_handler(const failure_t failure) { // --- GREENTEA HANDLERS --- status_t utest::v1::greentea_test_setup_handler(const size_t number_of_cases) { + UTEST_LOG_FUNCTION greentea_send_kv(TEST_ENV_TESTCASE_COUNT, number_of_cases); return verbose_test_setup_handler(number_of_cases); } void utest::v1::greentea_test_teardown_handler(const size_t passed, const size_t failed, const failure_t failure) { + UTEST_LOG_FUNCTION verbose_test_teardown_handler(passed, failed, failure); greentea_send_kv(TEST_ENV_TESTCASE_SUMMARY, passed, failed); int result = !(failed || (failure.reason && !(failure.reason & REASON_IGNORE))); @@ -98,12 +105,14 @@ void utest::v1::greentea_test_teardown_handler(const size_t passed, const size_t void utest::v1::greentea_test_failure_handler(const failure_t failure) { + UTEST_LOG_FUNCTION verbose_test_failure_handler(failure); } // --- GREENTEA CASE HANDLERS --- status_t utest::v1::greentea_case_setup_handler(const Case *const source, const size_t index_of_case) { + UTEST_LOG_FUNCTION status_t status = verbose_case_setup_handler(source, index_of_case); greentea_send_kv(TEST_ENV_TESTCASE_START, source->get_description()); return status; @@ -111,17 +120,20 @@ status_t utest::v1::greentea_case_setup_handler(const Case *const source, const status_t utest::v1::greentea_case_teardown_handler(const Case *const source, const size_t passed, const size_t failed, const failure_t failure) { + UTEST_LOG_FUNCTION greentea_send_kv(TEST_ENV_TESTCASE_FINISH, source->get_description(), passed, failed); return verbose_case_teardown_handler(source, passed, failed, failure); } status_t utest::v1::greentea_case_failure_abort_handler(const Case *const source, const failure_t failure) { + UTEST_LOG_FUNCTION status_t status = verbose_case_failure_handler(source, failure); return (status == STATUS_IGNORE) ? STATUS_IGNORE : STATUS_ABORT; } status_t utest::v1::greentea_case_failure_continue_handler(const Case *const source, const failure_t failure) { + UTEST_LOG_FUNCTION return verbose_case_failure_handler(source, failure); } diff --git a/frameworks/utest/source/harness.cpp b/frameworks/utest/source/harness.cpp index 8403bffcd1..45cab574e1 100644 --- a/frameworks/utest/source/harness.cpp +++ b/frameworks/utest/source/harness.cpp @@ -17,6 +17,8 @@ */ #include "utest/harness.h" +#include "utest/stack_trace.h" + #include using namespace utest::v1; @@ -53,16 +55,19 @@ namespace } static void die() { + UTEST_LOG_FUNCTION while(1) ; } static bool is_scheduler_valid(const utest_v1_scheduler_t scheduler) { + UTEST_LOG_FUNCTION return (scheduler.init && scheduler.post && scheduler.cancel && scheduler.run); } bool Harness::set_scheduler(const utest_v1_scheduler_t scheduler) { + UTEST_LOG_FUNCTION if (is_scheduler_valid(scheduler)) { ::scheduler = scheduler; return true; @@ -72,11 +77,13 @@ bool Harness::set_scheduler(const utest_v1_scheduler_t scheduler) bool Harness::run(const Specification& specification, size_t) { + UTEST_LOG_FUNCTION return run(specification); } bool Harness::run(const Specification& specification) { + UTEST_LOG_FUNCTION // check if a specification is currently running if (is_busy()) return false; @@ -142,6 +149,7 @@ bool Harness::run(const Specification& specification) void Harness::raise_failure(const failure_reason_t reason) { + UTEST_LOG_FUNCTION // ignore a failure, if the Harness has not been initialized. // this allows using unity assertion macros without setting up utest. if (test_cases == NULL) return; @@ -187,6 +195,7 @@ void Harness::raise_failure(const failure_reason_t reason) void Harness::schedule_next_case() { + UTEST_LOG_FUNCTION if (!case_timeout_occurred && case_failed_before == case_failed) { case_passed++; } @@ -195,6 +204,7 @@ void Harness::schedule_next_case() location = LOCATION_CASE_TEARDOWN; if (handlers.case_teardown) { + // printf("Schedule next case: case_passed = %d, case_failed = %d\n", case_passed, case_failed); status_t status = handlers.case_teardown(case_current, case_passed, case_failed, case_failed ? failure_t(REASON_CASES, LOCATION_UNKNOWN) : failure_t(REASON_NONE)); if (status < STATUS_CONTINUE) raise_failure(REASON_CASE_TEARDOWN); @@ -221,6 +231,7 @@ void Harness::schedule_next_case() void Harness::handle_timeout() { + UTEST_LOG_FUNCTION { UTEST_ENTER_CRITICAL_SECTION; @@ -238,11 +249,14 @@ void Harness::handle_timeout() void Harness::validate_callback(const control_t control) { + UTEST_LOG_FUNCTION UTEST_ENTER_CRITICAL_SECTION; case_validation_count++; + // printf("validate_callback: case_validation_count = %d\n", case_validation_count); if (case_timeout_handle != NULL || case_control.timeout == TIMEOUT_FOREVER) { + // printf("Cancelling scheduled callback\n"); scheduler.cancel(case_timeout_handle); case_timeout_handle = NULL; control_t merged_control = case_control + control; @@ -255,6 +269,7 @@ void Harness::validate_callback(const control_t control) bool Harness::is_busy() { + UTEST_LOG_FUNCTION UTEST_ENTER_CRITICAL_SECTION; if (!test_cases) return false; if (!case_current) return false; @@ -266,6 +281,7 @@ bool Harness::is_busy() void Harness::run_next_case() { + UTEST_LOG_FUNCTION if(case_current < (test_cases + test_length)) { handlers.case_setup = defaults.get_handler(case_current->setup_handler); diff --git a/frameworks/utest/source/shim.cpp b/frameworks/utest/source/shim.cpp index 4065a16516..31adecc409 100644 --- a/frameworks/utest/source/shim.cpp +++ b/frameworks/utest/source/shim.cpp @@ -17,6 +17,7 @@ */ #include "utest/shim.h" +#include "utest/stack_trace.h" #if UTEST_SHIM_SCHEDULER_USE_MINAR #include "minar/minar.h" @@ -57,55 +58,66 @@ utest_v1_scheduler_t utest_v1_get_scheduler() #ifdef YOTTA_MBED_HAL_VERSION_STRING # include "mbed-hal/us_ticker_api.h" #else -# include "us_ticker_api.h" +# include "mbed.h" #endif // only one callback is active at any given time static volatile utest_v1_harness_callback_t minimal_callback; static volatile utest_v1_harness_callback_t ticker_callback; -static const ticker_data_t *ticker_data; -static ticker_event_t ticker_event; -static void ticker_handler(uint32_t) +// Timeout object used to control the scheduling of test case callbacks +Timeout utest_timeout_object; + +static void ticker_handler() { - // printf("\t\t>>> Ticker callback fired for %p.\n", ticker_callback); + UTEST_LOG_FUNCTION + //printf("\t\t>>> Ticker callback fired for %p.\n", ticker_callback); minimal_callback = ticker_callback; } static int32_t utest_us_ticker_init() { - ticker_data = get_us_ticker_data(); - ticker_set_handler(ticker_data, ticker_handler); + UTEST_LOG_FUNCTION + // Ticker scheduler does not require any initialisation so return immediately return 0; } -static void *utest_us_ticker_post(const utest_v1_harness_callback_t callback, const uint32_t delay_ms) +static void *utest_us_ticker_post(const utest_v1_harness_callback_t callback, timestamp_t delay_ms) { - // printf("\t\t>>> Schedule %p with %ums delay => %p.\n", callback, (unsigned int)delay_ms, (void*)1); + UTEST_LOG_FUNCTION + timestamp_t delay_us = delay_ms *1000; + + //printf("\t\t>>> Schedule %p with %ums delay => %p.\n", callback, (unsigned int)delay_ms, (void*)1); if (delay_ms) { ticker_callback = callback; // fire the interrupt in 1000us * delay_ms - ticker_insert_event(ticker_data, &ticker_event, ticker_read(ticker_data) + delay_ms * 1000, 0); - } else { + utest_timeout_object.attach_us(ticker_handler, delay_us); + + } + else { minimal_callback = callback; } + //printf("Minimal callback = %p, ticker_callback = %p\n", minimal_callback, ticker_callback); + // return a bogus handle return (void*)1; } static int32_t utest_us_ticker_cancel(void *handle) { - // printf("\t\t>>> Cancel %p => %u\n", handle, (unsigned int)0); + UTEST_LOG_FUNCTION + //printf("\t\t>>> Cancel %p => %u\n", handle, (unsigned int)0); (void) handle; - ticker_remove_event(ticker_data, &ticker_event); + utest_timeout_object.detach(); return 0; } static int32_t utest_us_ticker_run() { + UTEST_LOG_FUNCTION while(1) { // check if a new callback has been set if (minimal_callback) { - // printf("\t\t>>> Firing callback %p\n", minimal_callback); + //printf("\t\t>>> Firing callback %p\n", minimal_callback); // copy the callback utest_v1_harness_callback_t callback = minimal_callback; // reset the shared callback @@ -126,6 +138,7 @@ static const utest_v1_scheduler_t utest_v1_scheduler = }; utest_v1_scheduler_t utest_v1_get_scheduler() { + UTEST_LOG_FUNCTION return utest_v1_scheduler; } } diff --git a/frameworks/utest/source/stack_trace.cpp b/frameworks/utest/source/stack_trace.cpp new file mode 100644 index 0000000000..c44d2260f1 --- /dev/null +++ b/frameworks/utest/source/stack_trace.cpp @@ -0,0 +1,67 @@ +/**************************************************************************** + * Copyright (c) 2016, ARM Limited, All Rights Reserved + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +#ifdef UTEST_STACK_TRACE + +#include "test_env.h" +#include "mbed.h" +#include "utest.h" +#include "unity.h" +#include "utest/stack_trace.h" + +#include + +using namespace utest::v1; + +static unsigned trace_index = 0; +static unsigned total_calls = 0; + +void utest_trace_initialise() +{ + total_calls = 0; + trace_index = 0; + for(unsigned i = 0; i < UTEST_MAX_BACKTRACE; i++) { + utest_trace[i].clear(); + } +} + +void utest_add_to_trace(char *func_name) +{ + + // Check if we have already used this entry. If so free the previously allocated + // string. + utest_trace[trace_index].clear(); + utest_trace[trace_index] = std::string(func_name); + trace_index = (trace_index + 1 == UTEST_MAX_BACKTRACE) ? 0 : trace_index + 1; + total_calls ++; +} + +void utest_dump_trace() +{ + unsigned current = (trace_index == 0) ? UTEST_MAX_BACKTRACE - 1 : trace_index - 1; + + printf("==================================================================\n"); + printf("Utest back trace: Total calls logged = %u.\n", total_calls); + printf("==================================================================\n"); + while (current != trace_index) { + + printf("%u > %s\n", current, utest_trace[current].c_str()); + current = (current == 0) ? UTEST_MAX_BACKTRACE - 1 : current - 1; + } + printf("==================================================================\n"); +} + +#endif diff --git a/frameworks/utest/source/unity_handler.cpp b/frameworks/utest/source/unity_handler.cpp index bc595233aa..e58d15447b 100644 --- a/frameworks/utest/source/unity_handler.cpp +++ b/frameworks/utest/source/unity_handler.cpp @@ -17,15 +17,19 @@ */ #include "utest/harness.h" + #include "utest/stack_trace.h" + extern "C" void utest_unity_assert_failure() { + UTEST_LOG_FUNCTION utest::v1::Harness::raise_failure(utest::v1::REASON_ASSERTION); } extern "C" void utest_unity_ignore_failure() { + UTEST_LOG_FUNCTION utest::v1::Harness::raise_failure(utest::v1::failure_reason_t(utest::v1::REASON_ASSERTION | utest::v1::REASON_IGNORE)); } diff --git a/frameworks/utest/utest/scheduler.h b/frameworks/utest/utest/scheduler.h index 55d83e97b2..e1f342dd88 100644 --- a/frameworks/utest/utest/scheduler.h +++ b/frameworks/utest/utest/scheduler.h @@ -19,6 +19,7 @@ #ifndef UTEST_SCHEDULER_H #define UTEST_SCHEDULER_H +#include "mbed.h" #include #include #include @@ -60,7 +61,7 @@ typedef int32_t (*utest_v1_scheduler_init_callback_t)(void); * @param delay_ms the delay in milliseconds after which the callback should be executed * @return A handle to identify the scheduled callback, or `NULL` for failure. */ -typedef void *(*utest_v1_scheduler_post_callback_t)(const utest_v1_harness_callback_t callback, const uint32_t delay_ms); +typedef void *(*utest_v1_scheduler_post_callback_t)(const utest_v1_harness_callback_t callback, timestamp_t delay_ms); /** * utest needs to cancel callbacks with a non-zero delay some time later. diff --git a/frameworks/utest/utest/stack_trace.h b/frameworks/utest/utest/stack_trace.h new file mode 100644 index 0000000000..e484c0c990 --- /dev/null +++ b/frameworks/utest/utest/stack_trace.h @@ -0,0 +1,44 @@ +/**************************************************************************** + * Copyright (c) 2016, ARM Limited, All Rights Reserved + * SPDX-License-Identifier: Apache-2.0 + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may + * not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT + * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + **************************************************************************** + */ + +#ifndef UTEST_STACK_TRACE_H +#define UTEST_STACK_TRACE_H + +#ifdef UTEST_STACK_TRACE +#include + +#define UTEST_MAX_BACKTRACE 100 +extern std::string utest_trace[UTEST_MAX_BACKTRACE]; + +extern void utest_trace_initialise(); +extern void utest_add_to_trace(char *func_name); +extern void utest_dump_trace(); + +#define UTEST_LOG_FUNCTION utest_add_to_trace((char *)__func__); +#define UTEST_TRACE_START utest_trace_initialise(); +#define UTEST_DUMP_TRACE utest_dump_trace(); + +#else + +#define UTEST_LOG_FUNCTION +#define UTEST_TRACE_START +#define UTEST_DUMP_TRACE + +#endif // UTEST_STACK_TRACE + +#endif // UTEST_STACK_TRACE_H