From e06ed6d69490081787d58eabca7267e7d385cf89 Mon Sep 17 00:00:00 2001 From: Stefan Kerkmann Date: Sun, 23 Jan 2022 19:00:41 +0100 Subject: [PATCH] Add timestamps to test fixture logging events and reset timer for each test --- platforms/test/timer.c | 3 ++- tests/test_common/matrix.c | 6 ++++-- tests/test_common/test_fixture.cpp | 18 ++++++++++-------- tests/test_common/test_keymap_key.cpp | 17 ++++++++++++++--- tests/test_common/test_keymap_key.hpp | 3 ++- tests/test_common/test_logger.cpp | 12 +++++++++--- tests/test_common/test_logger.hpp | 3 ++- 7 files changed, 43 insertions(+), 19 deletions(-) diff --git a/platforms/test/timer.c b/platforms/test/timer.c index 61c3a002011b..f35c23d5d74b 100644 --- a/platforms/test/timer.c +++ b/platforms/test/timer.c @@ -15,8 +15,9 @@ */ #include "timer.h" +#include -static uint32_t current_time = 0; +static atomic_uint_least32_t current_time = 0; void timer_init(void) { current_time = 0; } diff --git a/tests/test_common/matrix.c b/tests/test_common/matrix.c index 9a92a801c780..d72fe4abd053 100644 --- a/tests/test_common/matrix.c +++ b/tests/test_common/matrix.c @@ -38,9 +38,11 @@ void matrix_init_kb(void) {} void matrix_scan_kb(void) {} -void press_key(uint8_t col, uint8_t row) { matrix[row] |= 1 << col; } +void press_key(uint8_t col, uint8_t row) { matrix[row] |= (matrix_row_t)1 << col; } -void release_key(uint8_t col, uint8_t row) { matrix[row] &= ~(1 << col); } +void release_key(uint8_t col, uint8_t row) { matrix[row] &= ~((matrix_row_t)1 << col); } + +bool matrix_is_on(uint8_t row, uint8_t col) { return (matrix[row] & ((matrix_row_t)1 << col)); } void clear_all_keys(void) { memset(matrix, 0, sizeof(matrix)); } diff --git a/tests/test_common/test_fixture.cpp b/tests/test_common/test_fixture.cpp index 91bf3e779ec9..e3ec92acf948 100644 --- a/tests/test_common/test_fixture.cpp +++ b/tests/test_common/test_fixture.cpp @@ -12,6 +12,7 @@ #include "test_logger.hpp" #include "test_matrix.h" #include "test_keymap_key.hpp" +#include "timer.h" extern "C" { #include "action.h" @@ -41,6 +42,7 @@ extern "C" uint16_t keymap_key_to_keycode(uint8_t layer, keypos_t position) { } void TestFixture::SetUpTestCase() { + test_logger.info() << "Tapping Term is " << +TAPPING_TERM << "ms" << std::endl; test_logger.info() << "TestFixture setup-up start." << std::endl; // The following is enough to bootstrap the values set in main @@ -55,7 +57,10 @@ void TestFixture::SetUpTestCase() { void TestFixture::TearDownTestCase() {} -TestFixture::TestFixture() { m_this = this; } +TestFixture::TestFixture() { + m_this = this; + timer_clear(); +} TestFixture::~TestFixture() { test_logger.info() << "TestFixture clean-up start." << std::endl; @@ -83,11 +88,9 @@ TestFixture::~TestFixture() { EXPECT_CALL(driver, send_keyboard_mock(_)).Times(0); idle_for(TAPPING_TERM * 10); testing::Mock::VerifyAndClearExpectations(&driver); - m_this = nullptr; test_logger.info() << "TestFixture clean-up end." << std::endl; - print_test_log(); } @@ -142,14 +145,13 @@ void TestFixture::get_keycode(const layer_t layer, const keypos_t position, uint FAIL() << "No key is mapped for layer " << +layer << " and (column,row) " << +position.col << "," << +position.row << ")"; } -void TestFixture::run_one_scan_loop() { - keyboard_task(); - advance_time(1); -} +void TestFixture::run_one_scan_loop() { this->idle_for(1); } void TestFixture::idle_for(unsigned time) { + test_logger.trace() << "Running " << +time << " keyboard task loop(s)" << std::endl; for (unsigned i = 0; i < time; i++) { - run_one_scan_loop(); + keyboard_task(); + advance_time(1); } } diff --git a/tests/test_common/test_keymap_key.cpp b/tests/test_common/test_keymap_key.cpp index 878ae097bfa2..424448965e95 100644 --- a/tests/test_common/test_keymap_key.cpp +++ b/tests/test_common/test_keymap_key.cpp @@ -15,16 +15,27 @@ */ #include "test_keymap_key.hpp" +#include +#include "matrix.h" #include "test_logger.hpp" #include "gtest/gtest-message.h" #include "gtest/gtest.h" +#include "timer.h" void KeymapKey::press() { - test_logger.trace() << "Key pressed: (" << +this->position.col << "," << +this->position.row << ")" << std::endl; + EXPECT_FALSE(matrix_is_on(position.row, position.col)) << "Tried to press key (" << +this->position.col << "," << +this->position.row << ") " + << "that wasn't pressed before! Check the test code." << std::endl; + press_key(this->position.col, this->position.row); + this->timestamp_pressed = timer_read32(); + test_logger.trace() << "Key pressed: (" << +this->position.col << "," << +this->position.row << ")" << std::endl; } void KeymapKey::release() { - test_logger.trace() << "Key released: (" << +this->position.col << "," << +this->position.row << ")" << std::endl; + EXPECT_TRUE(matrix_is_on(this->position.row, this->position.col)) << "Tried to release key (" << +this->position.col << "," << +this->position.row << ") " + << "that wasn't pressed before! Check the test code." << std::endl; + release_key(this->position.col, this->position.row); -} \ No newline at end of file + uint32_t now = timer_read32(); + test_logger.trace() << "Key released: (" << +this->position.col << "," << +this->position.row << ") was pressed for " << now - this->timestamp_pressed << "ms" << std::endl; +} diff --git a/tests/test_common/test_keymap_key.hpp b/tests/test_common/test_keymap_key.hpp index 7861cb4a324e..f3fd81eea16e 100644 --- a/tests/test_common/test_keymap_key.hpp +++ b/tests/test_common/test_keymap_key.hpp @@ -43,4 +43,5 @@ struct KeymapKey { assert(position.col <= MATRIX_COLS); assert(position.row <= MATRIX_ROWS); } -}; \ No newline at end of file + uint32_t timestamp_pressed; +}; diff --git a/tests/test_common/test_logger.cpp b/tests/test_common/test_logger.cpp index 959fdde5ec56..094113c2c092 100644 --- a/tests/test_common/test_logger.cpp +++ b/tests/test_common/test_logger.cpp @@ -14,26 +14,32 @@ * along with this program. If not, see . */ +#include #include #include "test_logger.hpp" +#include "timer.h" TestLogger test_logger; TestLogger& TestLogger::info() { *this << "[ INFO ] "; - return *this; + return this->timestamp(); } TestLogger& TestLogger::trace() { *this << "[ TRACE ] "; - return *this; + return this->timestamp(); } TestLogger& TestLogger::error() { *this << "[ ERROR ] "; - return *this; + return this->timestamp(); } +TestLogger& TestLogger::timestamp() { + *this << std::setw(4) << timer_read32() << " "; + return *this; +} void TestLogger::reset() { this->m_log.str(""); }; void TestLogger::print_log() { std::cerr << this->m_log.str(); } diff --git a/tests/test_common/test_logger.hpp b/tests/test_common/test_logger.hpp index 348af7fab860..af15518e8a5e 100644 --- a/tests/test_common/test_logger.hpp +++ b/tests/test_common/test_logger.hpp @@ -29,7 +29,8 @@ class TestLogger : public std::ostream { void reset(); private: + TestLogger& timestamp(); std::stringbuf m_log; }; -extern TestLogger test_logger; \ No newline at end of file +extern TestLogger test_logger;