Remove all printfs from test cases which may directly or indirectly run

from an interrupt context. Where required add flags to functions and check
the values in the case teardowns. This allows validation that the case
callback was invoked without the need for an ASSERT or printf directly in
the callback.
In cases where a printf is still required in a test case but it is unclear
whether the code may or may not get called from interrupt context, a new
printf alternative, utest_printf() should be used instead. This just
checks whether the code is executing in interrupt context and only passes
its arguments to printf if not.

Author: adbridge

frameworks/utest/TESTS/unit_tests/basic_test/main.cpp

@@ -9,19 +9,17 @@ using namespace utest::v1;
 void test_simple() {
     UTEST_LOG_FUNCTION();
     TEST_ASSERT_EQUAL(0, 0);
-    printf("Simple test called\n");
 }
 
 utest::v1::status_t test_repeats_setup(const Case *const source, const size_t index_of_case) {
     UTEST_LOG_FUNCTION();
     // Call the default handler for proper reporting
     utest::v1::status_t status = greentea_case_setup_handler(source, index_of_case);
-    printf("Setting up for '%s'\n", source->get_description());
+    utest_printf("Setting up for '%s'\n", source->get_description());
     return status;
 }
 control_t test_repeats(const size_t call_count) {
     UTEST_LOG_FUNCTION();
-    printf("Called for the %u. time\n", call_count);
     TEST_ASSERT_NOT_EQUAL(3, call_count);
     // Specify how often this test is repeated ie. n total calls
     return (call_count < 2) ? CaseRepeatAll : CaseNext;

frameworks/utest/TESTS/unit_tests/case_async_validate/main.cpp

@@ -31,13 +31,11 @@ static Timeout utest_to;
 void simple_validation()
 {
     TEST_ASSERT_EQUAL(1, call_counter++);
-    printf("Simple validation callback executed.\n");
     Harness::validate_callback();
 }
 
 control_t simple_validation_case()
 {
-    printf("Simple validation, posting callback\n");
     TEST_ASSERT_EQUAL(0, call_counter++);
     utest_to.attach_us(simple_validation, 100); // Fire after 100 us
 
@@ -47,8 +45,6 @@ control_t simple_validation_case()
 // Validate: Multiple Validation --------------------------------------------------------------------------------------
 void multiple_validation()
 {
-    printf("Multiple validation callback executed.\n");
-
     // make sure validation is side-effect free
     TEST_ASSERT_EQUAL(3, call_counter++);
     Harness::validate_callback();
@@ -67,7 +63,6 @@ void multiple_validation()
 control_t multiple_validation_case()
 {
     TEST_ASSERT_EQUAL(2, call_counter++);
-    printf("Multiple validation callback posted.\n");
     utest_to.attach_us(multiple_validation, 100000); // Fire after 100 ms
     return CaseAwait;
 }
@@ -135,15 +130,13 @@ utest::v1::status_t multiple_premature_validation_case_teardown(const Case *cons
 void attributed_validation_cancel_repeat()
 {
     TEST_ASSERT_EQUAL(19, call_counter++);
-    printf("Validation cancel repeat callback executed.\n");
     // cancel all repeats
     Harness::validate_callback(CaseNoRepeat);
 }
 
 control_t attributed_validation_cancel_repeat_case()
 {
     TEST_ASSERT_EQUAL(18, call_counter++);
-    printf("Validation cancel repeat callback posted.\n");
 
     utest_to.attach_us(attributed_validation_cancel_repeat, 100000); // Fire after 100 ms
     // the RepeatAll will be cancelled during callback validation
@@ -163,7 +156,6 @@ utest::v1::status_t attributed_validation_cancel_repeat_case_teardown(const Case
 // Validate: Attributed Validation: Enable Repeat Handler -------------------------------------------------------------
 void attributed_validation_enable_repeat()
 {
-    printf("Validation enable repeat callback executed.\n");
     TEST_ASSERT_EQUAL(22, call_counter++);
     // cancel all repeats
     Harness::validate_callback(CaseRepeatHandler);
@@ -177,7 +169,6 @@ control_t attributed_validation_enable_repeat_case(const size_t call_count)
 {
     if (call_count == 1) {
         TEST_ASSERT_EQUAL(21, call_counter++);
-        printf("Validation enable repeat callback posted.\n");
         utest_to.attach_us(attributed_validation_enable_repeat, 100000); // Fire after 100 ms
         // the RepeatAll will be cancelled during callback validation
         return CaseAwait;

frameworks/utest/TESTS/unit_tests/case_control_async/main.cpp

@@ -46,7 +46,6 @@ class Utest_func_bind {
 void await_case_validate(int expected_call_count) 
 {
     UTEST_LOG_FUNCTION();
-    printf("await_case_validate called with expected call count of %d\n", expected_call_count);
     TEST_ASSERT_EQUAL(expected_call_count, call_counter++);
     Harness::validate_callback();
 }
@@ -142,13 +141,11 @@ utest::v1::status_t repeat_all_on_timeout_case_setup(const Case *const source, c
 control_t repeat_all_on_timeout_case(const size_t call_count)
 {
     UTEST_LOG_FUNCTION();
-    printf("Running case handler for %u. time\n", call_count);
     static int repeat_counter(1);
     TEST_ASSERT_EQUAL(repeat_counter++, call_count);
     TEST_ASSERT(call_count <= 10);
     TEST_ASSERT_EQUAL((call_count-1)*3 + 9, call_counter++);
     if (call_count == 10) {
-        printf("Scheduling await_case_validate with value 37");
         utest_to.attach_us(&validate2, &Utest_func_bind::callback, (50*1000)); // Fire after 50ms
     }
     return CaseRepeatAllOnTimeout(100);
@@ -157,7 +154,6 @@ utest::v1::status_t repeat_all_on_timeout_case_teardown(const Case *const source
 {
     UTEST_LOG_FUNCTION();
     static int repeat_counter(0);
-    printf("Call counter = %d, passed =%u, failed = %u\n", call_counter, passed, failed);
 
     TEST_ASSERT_EQUAL((call_counter == 38) ? 1 : 0, passed);
     TEST_ASSERT_EQUAL(0, failed);
@@ -180,13 +176,11 @@ utest::v1::status_t repeat_handler_on_timeout_case_setup(const Case *const sourc
 control_t repeat_handler_on_timeout_case(const size_t call_count)
 {
     UTEST_LOG_FUNCTION();
-    printf("Running case handler for %u. time\n", call_count);
     static int repeat_counter(1);
     TEST_ASSERT_EQUAL(repeat_counter++, call_count);
     TEST_ASSERT(call_count <= 10);
     TEST_ASSERT_EQUAL(call_count-1 + 40, call_counter++);
     if (call_count == 10) {
-        printf("Scheduling await_case_validate with value 50");
         utest_to.attach_us(&validate3, &Utest_func_bind::callback, (50*1000)); // Fire after 50ms
     }
     return CaseRepeatHandlerOnTimeout(100);

frameworks/utest/TESTS/unit_tests/case_control_repeat/main.cpp

@@ -34,7 +34,6 @@ utest::v1::status_t repeat_all_case_setup(const Case *const source, const size_t
 }
 control_t repeat_all_case(const size_t call_count)
 {
-    printf("Running case handler for %u. time\n", call_count);
     static int repeat_counter(1);
     TEST_ASSERT_EQUAL(repeat_counter++, call_count);
     TEST_ASSERT_EQUAL((call_count-1)*3 + 1, call_counter++);
@@ -61,7 +60,6 @@ utest::v1::status_t repeat_handler_case_setup(const Case *const source, const si
 }
 control_t repeat_handler_case(const size_t call_count)
 {
-    printf("Running case handler for %u. time\n", call_count);
     static int repeat_counter(1);
     TEST_ASSERT_EQUAL(repeat_counter++, call_count);
     TEST_ASSERT_EQUAL((call_count-1) + 31, call_counter++);

frameworks/utest/TESTS/unit_tests/case_selection/main.cpp

@@ -23,13 +23,17 @@
 using namespace utest::v1;
 
 static int call_counter(0);
+static bool executed_case_0 = false;
+static bool executed_case_1 = false;
+static bool executed_case_2 = false;
 
 void handler_case_2()
 {
-    printf("Executing Case 2...\n");
+    executed_case_2 = true;
 }
 utest::v1::status_t teardown_case_2(const Case *const source, const size_t passed, const size_t failed, const failure_t failure)
 {
+    TEST_ASSERT_TRUE(executed_case_2);
     TEST_ASSERT_EQUAL(1, passed);
     TEST_ASSERT_EQUAL(0, failed);
     TEST_ASSERT_EQUAL(REASON_NONE, failure.reason);
@@ -40,10 +44,11 @@ utest::v1::status_t teardown_case_2(const Case *const source, const size_t passe
 }
 void handler_case_0()
 {
-    printf("Executing Case 0...\n");
+    executed_case_0 = true;
 }
 utest::v1::status_t teardown_case_0(const Case *const source, const size_t passed, const size_t failed, const failure_t failure)
 {
+    TEST_ASSERT_TRUE(executed_case_0);
     TEST_ASSERT_EQUAL(1, passed);
     TEST_ASSERT_EQUAL(0, failed);
     TEST_ASSERT_EQUAL(REASON_NONE, failure.reason);
@@ -54,10 +59,11 @@ utest::v1::status_t teardown_case_0(const Case *const source, const size_t passe
 }
 void handler_case_1()
 {
-    printf("Executing Case 1...\n");
+    executed_case_1 = true;
 }
 utest::v1::status_t teardown_case_1(const Case *const source, const size_t passed, const size_t failed, const failure_t failure)
 {
+    TEST_ASSERT_TRUE(executed_case_1);
     TEST_ASSERT_EQUAL(1, passed);
     TEST_ASSERT_EQUAL(0, failed);
     TEST_ASSERT_EQUAL(REASON_NONE, failure.reason);

frameworks/utest/TESTS/unit_tests/case_setup_failure/main.cpp

@@ -22,10 +22,11 @@
 using namespace utest::v1;
 
 static int call_counter(0);
+static bool never_call = false;
 
 void never_call_case()
 {
-    TEST_FAIL_MESSAGE("Case handler should have never been called!");
+      never_call = true;
 }
 
 utest::v1::status_t abort_case_setup(const Case *const source, const size_t index_of_case)
@@ -38,6 +39,7 @@ utest::v1::status_t abort_case_setup(const Case *const source, const size_t inde
 
 utest::v1::status_t abort_case_teardown(const Case *const source, const size_t passed, const size_t failed, const failure_t failure)
 {
+    TEST_ASSERT_FALSE_MESSAGE(never_call, "Case handler should never have been called!");
     TEST_ASSERT_EQUAL(1, call_counter);
     TEST_ASSERT_EQUAL(0, passed);
     TEST_ASSERT_EQUAL(1, failed);

frameworks/utest/TESTS/unit_tests/minimal_async_scheduler/main.cpp

@@ -38,7 +38,6 @@ static Timeout utest_minimal_object;
 static void ticker_handler()
 {
     UTEST_LOG_FUNCTION();
-//    printf("\t\t>>> Ticker callback fired for %p.\n", ticker_callback);
     minimal_callback = ticker_callback;
 }
 
@@ -52,7 +51,6 @@ static int32_t utest_minimal_init()
 static void *utest_minimal_post(const utest_v1_harness_callback_t callback,  timestamp_t delay_ms)
 {
     UTEST_LOG_FUNCTION();
-    // printf("\t\t>>> Schedule %p with %ums delay => %p.\n", callback, (unsigned int)delay_ms, (void*)1);
     timestamp_t delay_us = delay_ms *1000;
 
     if (delay_ms) {
@@ -69,7 +67,6 @@ static void *utest_minimal_post(const utest_v1_harness_callback_t callback,  tim
 static int32_t utest_minimal_cancel(void *handle)
 {
     UTEST_LOG_FUNCTION();
-    printf("\t\t>>> Cancel %p => %u\n", handle, (unsigned int)0);
     (void) handle;
     utest_minimal_object.detach();
     return 0;
@@ -86,7 +83,6 @@ static int32_t utest_minimal_run()
         // check if a new callback has been set
         if (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
@@ -114,7 +110,6 @@ control_t test_case()
     UTEST_LOG_FUNCTION();
     static int counter(0);
     TEST_ASSERT_EQUAL(counter++, call_counter++);
-    printf("Running Test #%d\n", counter);
     return CaseNext;
 }
 
@@ -124,7 +119,6 @@ control_t test_case_async()
     UTEST_LOG_FUNCTION();
     static int counter(3);
     TEST_ASSERT_EQUAL(counter++, call_counter++);
-    printf("Running Test #%d\n", counter);
     return CaseTimeout(200);
 }
 utest::v1::status_t test_case_async_failure(const Case *const source, const failure_t reason)

frameworks/utest/TESTS/unit_tests/minimal_scheduler/main.cpp

@@ -82,7 +82,6 @@ control_t test_case()
 {
     static int counter(0);
     TEST_ASSERT_EQUAL(counter++, call_counter++);
-    printf("Running Test #%d\n", counter);
     return CaseNext;
 }