diff --git a/right/src/test_suite/CLAUDE.md b/right/src/test_suite/CLAUDE.md index 312a6f715..9bedf5e80 100644 --- a/right/src/test_suite/CLAUDE.md +++ b/right/src/test_suite/CLAUDE.md @@ -99,5 +99,5 @@ TEST_SET_MACRO("j", "ifShortcut k final tapKey n\n holdKey j") - `TestSuite_Verbose` controls logging. - `LOG_VERBOSE(fmt, ...)` is conditional. - `TEST_EXPECT___________MAYBE` only logs in verbose mode. -- Failures are always logged immediately; failed tests are auto-rerun with verbose enabled. +- Failures are always logged immediately via `LOG_FAILURE(fmt, ...)`, which prints a separator before the first failure of a test; failed tests are auto-rerun with verbose enabled. - Reset `TestSuite_Verbose = false` after a verbose rerun. diff --git a/right/src/test_suite/CMakeLists.txt b/right/src/test_suite/CMakeLists.txt index f600bfccd..3e83bb097 100644 --- a/right/src/test_suite/CMakeLists.txt +++ b/right/src/test_suite/CMakeLists.txt @@ -20,4 +20,5 @@ target_sources(${PROJECT_NAME} PRIVATE tests/test_playtime.c tests/test_transport.c tests/test_tapkeyseq.c + tests/test_fail.c ) diff --git a/right/src/test_suite/test_input_machine.c b/right/src/test_suite/test_input_machine.c index 3db8c1214..1598f1ac4 100644 --- a/right/src/test_suite/test_input_machine.c +++ b/right/src/test_suite/test_input_machine.c @@ -85,7 +85,7 @@ static bool validateReport(const char *expectShortcuts, bool logFailure) { key_action_t keyAction = { 0 }; if (!MacroShortcutParser_Parse(at, shortcutEnd, MacroSubAction_Tap, NULL, &keyAction)) { - if (logFailure) LogU("[TEST] FAIL: invalid shortcut in '%s'\n", expectShortcuts); + if (logFailure) LOG_FAILURE("[TEST] FAIL: invalid shortcut in '%s'\n", expectShortcuts); return false; } @@ -107,7 +107,7 @@ static bool validateReport(const char *expectShortcuts, bool logFailure) { if (KeyboardReport_ScancodeCount(actual) != scancodeCount) match = false; if (!match && logFailure) { - LogU("[TEST] < FAIL: Expect '%s', got '%s'\n", + LOG_FAILURE("[TEST] < FAIL: Expect '%s', got '%s'\n", expectShortcuts, Utils_GetUsbReportString(actual)); } @@ -150,7 +150,7 @@ void InputMachine_Tick(void) { EventVector_Set(EventVector_StateMatrix); EventVector_WakeMain(); } else { - LogU("[TEST] FAIL: Press [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: Press [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -166,7 +166,7 @@ void InputMachine_Tick(void) { EventVector_Set(EventVector_StateMatrix); EventVector_WakeMain(); } else { - LogU("[TEST] FAIL: Release [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: Release [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -192,7 +192,7 @@ void InputMachine_Tick(void) { case TestAction_SetAction: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetAction [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetAction [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -203,7 +203,7 @@ void InputMachine_Tick(void) { key_action_t keyAction = { 0 }; if (!MacroShortcutParser_Parse(shortcut, shortcutEnd, MacroSubAction_Tap, NULL, &keyAction)) { - LogU("[TEST] FAIL: SetAction [%s] = '%s' - invalid shortcut\n", action->keyId, action->shortcutStr); + LOG_FAILURE("[TEST] FAIL: SetAction [%s] = '%s' - invalid shortcut\n", action->keyId, action->shortcutStr); InputMachine_Failed = true; return; } @@ -217,7 +217,7 @@ void InputMachine_Tick(void) { case TestAction_SetMacro: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetMacro [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetMacro [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -238,7 +238,7 @@ void InputMachine_Tick(void) { case TestAction_SetLayerHold: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetLayerHold [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetLayerHold [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -261,7 +261,7 @@ void InputMachine_Tick(void) { case TestAction_SetLayerAction: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetLayerAction [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetLayerAction [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -272,7 +272,7 @@ void InputMachine_Tick(void) { key_action_t keyAction = { 0 }; if (!MacroShortcutParser_Parse(shortcut, shortcutEnd, MacroSubAction_Tap, NULL, &keyAction)) { - LogU("[TEST] FAIL: SetLayerAction layer %d [%s] = '%s' - invalid shortcut\n", action->layerId, action->keyId, action->shortcutStr); + LOG_FAILURE("[TEST] FAIL: SetLayerAction layer %d [%s] = '%s' - invalid shortcut\n", action->layerId, action->keyId, action->shortcutStr); InputMachine_Failed = true; return; } @@ -286,7 +286,7 @@ void InputMachine_Tick(void) { case TestAction_SetSecondaryRole: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetSecondaryRole [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetSecondaryRole [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } @@ -311,7 +311,7 @@ void InputMachine_Tick(void) { case TestAction_SetGenericAction: { uint8_t slotId, keyId; if (!parseKeyId(action->keyId, &slotId, &keyId)) { - LogU("[TEST] FAIL: SetGenericAction [%s] - invalid key\n", action->keyId); + LOG_FAILURE("[TEST] FAIL: SetGenericAction [%s] - invalid key\n", action->keyId); InputMachine_Failed = true; return; } diff --git a/right/src/test_suite/test_output_machine.c b/right/src/test_suite/test_output_machine.c index 31acf80c7..ecb9abea4 100644 --- a/right/src/test_suite/test_output_machine.c +++ b/right/src/test_suite/test_output_machine.c @@ -39,7 +39,7 @@ static bool validateReport(const usb_basic_keyboard_report_t *actual, const char key_action_t keyAction = { 0 }; if (!MacroShortcutParser_Parse(at, shortcutEnd, MacroSubAction_Tap, NULL, &keyAction)) { - if (logFailure) LogU("[TEST] FAIL: invalid shortcut in '%s'\n", expectShortcuts); + if (logFailure) LOG_FAILURE("[TEST] FAIL: invalid shortcut in '%s'\n", expectShortcuts); return false; } @@ -61,7 +61,7 @@ static bool validateReport(const usb_basic_keyboard_report_t *actual, const char if (UsbBasicKeyboard_ScancodeCount(actual) != scancodeCount) match = false; if (!match && logFailure) { - LogU("[TEST] < FAIL: Expect '%s', got '%s'\n", + LOG_FAILURE("[TEST] < FAIL: Expect '%s', got '%s'\n", expectShortcuts, Utils_GetUsbReportString(actual)); } diff --git a/right/src/test_suite/test_suite.c b/right/src/test_suite/test_suite.c index 9bdaf0b04..74f044757 100644 --- a/right/src/test_suite/test_suite.c +++ b/right/src/test_suite/test_suite.c @@ -31,6 +31,7 @@ static uint16_t currentModuleIndex = 0; static uint16_t currentTestIndex = 0; static uint16_t totalTestCount = 0; static uint16_t passedCount = 0; +static uint16_t partialCount = 0; static uint16_t failedCount = 0; // Module-scoped run limit @@ -48,6 +49,22 @@ static uint16_t rerunTestIndex = 0; static bool inInterTestDelay = false; static uint32_t interTestDelayStart = 0; +// Whether the current test (including its rerun) has opened its log with a separator +static bool separatorPrinted = false; + +void TestSuite_LogSeparatorOnce(void) { + if (!separatorPrinted) { + LogU("[TEST] ----------------------\n"); + separatorPrinted = true; + } +} + +static void closeTestLog(void) { + if (separatorPrinted) { + LogU("[TEST] ----------------------\n"); + } +} + static const test_t* getCurrentTest(void) { return &AllTestModules[currentModuleIndex]->tests[currentTestIndex]; } @@ -68,8 +85,11 @@ static void startTest(const test_t *test, const test_module_t *module) { ConfigManager_ResetConfiguration(false, false); LayerStack_Reset(); PostponerExtended_ResetPostponer(); + if (!isRerunning) { + separatorPrinted = false; + } if (TestSuite_Verbose) { - LogU("[TEST] ----------------------\n"); + TestSuite_LogSeparatorOnce(); LogU("[TEST] Running: %s/%s\n", module->name, test->name); } InputMachine_Start(test); @@ -127,11 +147,11 @@ void TestHooks_Tick(void) { if (isRerunning || singleTestMode) { // Already rerunning with verbose (or single test mode), log final result if (failed) { - LogU("[TEST] Finished: %s/%s - FAIL\n", module->name, test->name); + LOG_FAILURE("[TEST] Finished: %s/%s - FAIL\n", module->name, test->name); } else { - LogU("[TEST] Finished: %s/%s - TIMEOUT\n", module->name, test->name); + LOG_FAILURE("[TEST] Finished: %s/%s - TIMEOUT\n", module->name, test->name); } - LogU("[TEST] ----------------------\n"); + closeTestLog(); failedCount++; isRerunning = false; TestSuite_Verbose = false; // Reset to non-verbose for remaining tests @@ -152,9 +172,9 @@ void TestHooks_Tick(void) { } else { // First failure - log and save position for rerun with verbose if (failed) { - LogU("[TEST] Finished: %s/%s - FAIL (rerunning verbose)\n", module->name, test->name); + LOG_FAILURE("[TEST] Finished: %s/%s - FAIL (rerunning verbose)\n", module->name, test->name); } else { - LogU("[TEST] Finished: %s/%s - TIMEOUT (rerunning verbose)\n", module->name, test->name); + LOG_FAILURE("[TEST] Finished: %s/%s - TIMEOUT (rerunning verbose)\n", module->name, test->name); } rerunModuleIndex = currentModuleIndex; rerunTestIndex = currentTestIndex; @@ -165,12 +185,17 @@ void TestHooks_Tick(void) { interTestDelayStart = Timer_GetCurrentTime(); } } else { - LogU("[TEST] Finished: %s/%s - PASS\n", module->name, test->name); - passedCount++; if (isRerunning) { + // Failed in the first run, passed in the rerun + LogU("[TEST] Finished: %s/%s - PARTIAL (passed on rerun)\n", module->name, test->name); + partialCount++; isRerunning = false; TestSuite_Verbose = false; // Reset to non-verbose for remaining tests + } else { + LogU("[TEST] Finished: %s/%s - PASS\n", module->name, test->name); + passedCount++; } + closeTestLog(); if (singleTestMode) { goto finish; @@ -189,8 +214,11 @@ void TestHooks_Tick(void) { finish: Macros_StopAllMacros(); - LogU("[TEST] ----------------------\n"); - LogU("[TEST] Complete: %d passed, %d failed\n", passedCount, failedCount); + if (!separatorPrinted) { + // Otherwise the last test has already closed its log with a separator + LogU("[TEST] ----------------------\n"); + } + LogU("[TEST] Complete: %d passed, %d partial, %d failed\n", passedCount, partialCount, failedCount); TestHooks_Active = false; ConfigManager_ResetConfiguration(false, false); LayerStack_Reset(); @@ -205,6 +233,7 @@ uint8_t TestSuite_RunAll(void) { currentModuleIndex = 0; currentTestIndex = 0; passedCount = 0; + partialCount = 0; failedCount = 0; inInterTestDelay = false; isRerunning = false; @@ -262,6 +291,7 @@ uint8_t TestSuite_RunSingle(const char *moduleStart, const char *moduleEnd, cons currentModuleIndex = mi; currentTestIndex = ti; passedCount = 0; + partialCount = 0; failedCount = 0; inInterTestDelay = false; isRerunning = false; @@ -292,6 +322,7 @@ static uint8_t TestSuite_RunModule(const char *moduleStart, const char *moduleEn currentModuleIndex = mi; currentTestIndex = 0; passedCount = 0; + partialCount = 0; failedCount = 0; inInterTestDelay = false; isRerunning = false; diff --git a/right/src/test_suite/test_suite.h b/right/src/test_suite/test_suite.h index eb3d31313..d8932dc43 100644 --- a/right/src/test_suite/test_suite.h +++ b/right/src/test_suite/test_suite.h @@ -8,6 +8,12 @@ // Verbose logging mode - when true, logs each action extern bool TestSuite_Verbose; +// Logs a failure. The first failure of a test is preceded by a separator. +#define LOG_FAILURE(fmt, ...) do { TestSuite_LogSeparatorOnce(); LogU(fmt, ##__VA_ARGS__); } while(0) + +// Prints a separator unless the current test has already printed one. +void TestSuite_LogSeparatorOnce(void); + // Initialize the test suite. Call once at startup. void TestSuite_Init(void); diff --git a/right/src/test_suite/tests/test_fail.c b/right/src/test_suite/tests/test_fail.c new file mode 100644 index 000000000..afa372241 --- /dev/null +++ b/right/src/test_suite/tests/test_fail.c @@ -0,0 +1,24 @@ +#include "tests.h" + +// Always fails - used to verify that the test framework reports failures. +// Not part of the normal suite; uncomment it in AllTestModules[] to run it. +static const test_action_t test_fail[] = { + TEST_SET_ACTION("u", "u"), + TEST_PRESS______("u"), + TEST_DELAY__(50), + TEST_EXPECT__________("i"), + TEST_RELEASE__U("u"), + TEST_DELAY__(50), + TEST_EXPECT__________(""), + TEST_END() +}; + +static const test_t fail_tests[] = { + { .name = "fail", .actions = test_fail }, +}; + +const test_module_t TestModule_Fail = { + .name = "Fail", + .tests = fail_tests, + .testCount = sizeof(fail_tests) / sizeof(fail_tests[0]) +}; diff --git a/right/src/test_suite/tests/tests.c b/right/src/test_suite/tests/tests.c index ca5769e3e..10c1896b2 100644 --- a/right/src/test_suite/tests/tests.c +++ b/right/src/test_suite/tests/tests.c @@ -19,6 +19,8 @@ const test_module_t * const AllTestModules[] = { &TestModule_Playtime, &TestModule_Transport, &TestModule_TapKeySeq, + // Always fails; uncomment to check that the framework reports failures. + // &TestModule_Fail, }; const uint16_t AllTestModulesCount = sizeof(AllTestModules) / sizeof(AllTestModules[0]); diff --git a/right/src/test_suite/tests/tests.h b/right/src/test_suite/tests/tests.h index 360a489f3..79efd8724 100644 --- a/right/src/test_suite/tests/tests.h +++ b/right/src/test_suite/tests/tests.h @@ -33,5 +33,6 @@ extern const test_module_t TestModule_Sticky; extern const test_module_t TestModule_Playtime; extern const test_module_t TestModule_Transport; extern const test_module_t TestModule_TapKeySeq; +extern const test_module_t TestModule_Fail; #endif