From 1f9e239a7d8d93dea91f769fcbf6dd8ae84f9b90 Mon Sep 17 00:00:00 2001 From: Christopher Haster Date: Fri, 9 Dec 2016 17:28:03 -0600 Subject: [PATCH 1/4] events: Added equeue platform timing tests Tests the timer/semaphores at a lower level than the event queue, which removes a layer of concerns from issues in the rtos timing. --- TESTS/events/timing/main.cpp | 122 +++++++++++++++++++++++++++++++++++ 1 file changed, 122 insertions(+) create mode 100644 TESTS/events/timing/main.cpp diff --git a/TESTS/events/timing/main.cpp b/TESTS/events/timing/main.cpp new file mode 100644 index 00000000000..79554e6e152 --- /dev/null +++ b/TESTS/events/timing/main.cpp @@ -0,0 +1,122 @@ +#include "mbed_events.h" +#include "mbed.h" +#include "rtos.h" +#include "greentea-client/test_env.h" +#include "unity.h" +#include "utest.h" +#include +#include + +using namespace utest::v1; + + +// Test delay +#ifndef TEST_EVENTS_TIMING_TIME +#define TEST_EVENTS_TIMING_TIME 20000 +#endif + +#ifndef TEST_EVENTS_TIMING_MEAN +#define TEST_EVENTS_TIMING_MEAN 25 +#endif + +#ifndef M_PI +#define M_PI 3.14159265358979323846264338327950288 +#endif + +// Random number generation to skew timing values +float gauss(float mu, float sigma) { + float x = (float)rand() / ((float)RAND_MAX+1); + float y = (float)rand() / ((float)RAND_MAX+1); + float x2pi = x*2.0*M_PI; + float g2rad = sqrt(-2.0 * log(1.0-y)); + float z = cos(x2pi) * g2rad; + return mu + z*sigma; +} + +float chisq(float sigma) { + return pow(gauss(0, sqrt(sigma)), 2); +} + + +Timer timer; +DigitalOut led(LED1); + +equeue_sema_t sema; + +// Timer timing test +void timer_timing_test() { + timer.reset(); + timer.start(); + int prev = timer.read_us(); + + while (prev < TEST_EVENTS_TIMING_TIME*1000) { + int next = timer.read_us(); + if (next < prev) { + printf("backwards drift %d -> %d (%08x -> %08x)\r\n", + prev, next, prev, next); + } + TEST_ASSERT(next >= prev); + prev = next; + } +} + +// equeue tick timing test +void tick_timing_test() { + unsigned start = equeue_tick(); + int prev = 0; + + while (prev < TEST_EVENTS_TIMING_TIME) { + int next = equeue_tick() - start; + if (next < prev) { + printf("backwards drift %d -> %d (%08x -> %08x)\r\n", + prev, next, prev, next); + } + TEST_ASSERT(next >= prev); + prev = next; + } +} + +// equeue semaphore timing test +void semaphore_timing_test() { + srand(0); + timer.reset(); + timer.start(); + + int err = equeue_sema_create(&sema); + TEST_ASSERT_EQUAL(0, err); + + while (timer.read_ms() < TEST_EVENTS_TIMING_TIME) { + int delay = chisq(TEST_EVENTS_TIMING_MEAN); + + int start = timer.read_us(); + equeue_sema_wait(&sema, delay); + int taken = timer.read_us() - start; + + printf("delay %dms => error %dus\r\n", delay, abs(1000*delay - taken)); + TEST_ASSERT_INT_WITHIN(2000, taken, delay * 1000); + + led = !led; + } + + equeue_sema_destroy(&sema); +} + + +// Test setup +utest::v1::status_t test_setup(const size_t number_of_cases) { + GREENTEA_SETUP((number_of_cases+1)*TEST_EVENTS_TIMING_TIME, "default_auto"); + return verbose_test_setup_handler(number_of_cases); +} + +const Case cases[] = { + Case("Testing accuracy of timer", timer_timing_test), + Case("Testing accuracy of equeue tick", tick_timing_test), + Case("Testing accuracy of equeue semaphore", semaphore_timing_test), +}; + +Specification specification(test_setup, cases); + +int main() { + return !Harness::run(specification); +} + From c0951c9035801266bb6c457b9ed4c748a0053f61 Mon Sep 17 00:00:00 2001 From: Christopher Haster Date: Wed, 15 Feb 2017 09:45:52 -0600 Subject: [PATCH 2/4] NCS36510: Fixed drift in ticker interrupt The NCS36510 is limited to 16bit timers. Construction of larger intervals is performed in software by counting the number of 16bit intervals that pass. Either this counting takes a bit of time, or there is a math error somewhere (maybe a long critical section?), because there is a roughly ~1us delay between when the interrupt occurs and the ticker progresses onto the next 16bit interval. This is normally a completely reasonable error, except that the error accumulates. After a while, the equeue tests find themselves with tens of milliseconds of error. To make matters worse, this error is random because of other interrupts occuring in the system, making the exact issue quite a bit difficult to track down. This fix drops the software counter in favor of just recalculating the next delay interval from the target time and value of the running timer. The running timer used to calculate the current tick is left to overflow in hardware and doesn't have this drift. --- .../TARGET_NCS36510/ncs36510_us_ticker_api.c | 27 +++++++++++-------- 1 file changed, 16 insertions(+), 11 deletions(-) diff --git a/targets/TARGET_ONSEMI/TARGET_NCS36510/ncs36510_us_ticker_api.c b/targets/TARGET_ONSEMI/TARGET_NCS36510/ncs36510_us_ticker_api.c index 8ba37597753..abed10ef067 100644 --- a/targets/TARGET_ONSEMI/TARGET_NCS36510/ncs36510_us_ticker_api.c +++ b/targets/TARGET_ONSEMI/TARGET_NCS36510/ncs36510_us_ticker_api.c @@ -37,7 +37,7 @@ static int us_ticker_inited = 0; static void us_timer_init(void); -static uint32_t us_ticker_int_counter = 0; +static uint32_t us_ticker_target = 0; static volatile uint32_t msb_counter = 0; void us_ticker_init(void) @@ -168,20 +168,25 @@ extern void us_ticker_isr(void) /* Clear IRQ flag */ TIM1REG->CLEAR = 0; - /* If this is a longer timer it will take multiple full hw counter cycles */ - if (us_ticker_int_counter > 0) { - ticker_set(0xFFFF); - us_ticker_int_counter--; - } else { + int32_t delta = us_ticker_target - us_ticker_read(); + if (delta <= 0) { TIM1REG->CONTROL.BITS.ENABLE = False; us_ticker_irq_handler(); + } else { + // Clamp at max value of timer + if (delta > 0xFFFF) { + delta = 0xFFFF; + } + + ticker_set(delta); } } /* Set timer 1 ticker interrupt */ void us_ticker_set_interrupt(timestamp_t timestamp) { - int32_t delta = (uint32_t)timestamp - us_ticker_read(); + us_ticker_target = (uint32_t)timestamp; + int32_t delta = us_ticker_target - us_ticker_read(); if (delta <= 0) { /* This event was in the past */ @@ -195,10 +200,10 @@ void us_ticker_set_interrupt(timestamp_t timestamp) return; } - /* Calculate how much delta falls outside the 16-bit counter range. */ - /* You will have to perform a full timer overflow for each bit above */ - /* that range. */ - us_ticker_int_counter = (uint32_t)(delta >> 16); + // Clamp at max value of timer + if (delta > 0xFFFF) { + delta = 0xFFFF; + } ticker_set(delta); } From 0949164422da5efd583ddf5aa0c93423eeaf5972 Mon Sep 17 00:00:00 2001 From: Christopher Haster Date: Wed, 15 Feb 2017 10:04:11 -0600 Subject: [PATCH 3/4] events: Added better handling of desynchronized timers in platform layer An odd bug (c0951c9) in the NCS36510 ticker code caused the timer/ticker classes to become desynchronized. Updated the handling to not assume the timers are perfectly in synch. This will increase the event's tolerance of less robust platforms. --- events/equeue/equeue_mbed.cpp | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/events/equeue/equeue_mbed.cpp b/events/equeue/equeue_mbed.cpp index 9f1ce484deb..5c72b38dea3 100644 --- a/events/equeue/equeue_mbed.cpp +++ b/events/equeue/equeue_mbed.cpp @@ -26,15 +26,15 @@ // Ticker operations static bool equeue_tick_inited = false; -static unsigned equeue_minutes = 0; +static volatile unsigned equeue_minutes = 0; static unsigned equeue_timer[ (sizeof(Timer)+sizeof(unsigned)-1)/sizeof(unsigned)]; static unsigned equeue_ticker[ (sizeof(Ticker)+sizeof(unsigned)-1)/sizeof(unsigned)]; static void equeue_tick_update() { + equeue_minutes += reinterpret_cast(equeue_timer)->read_ms(); reinterpret_cast(equeue_timer)->reset(); - equeue_minutes += 1; } static void equeue_tick_init() { @@ -48,7 +48,7 @@ static void equeue_tick_init() { equeue_minutes = 0; reinterpret_cast(equeue_timer)->start(); reinterpret_cast(equeue_ticker) - ->attach_us(equeue_tick_update, (1 << 16)*1000); + ->attach_us(equeue_tick_update, 1000 << 16); equeue_tick_inited = true; } @@ -58,8 +58,15 @@ unsigned equeue_tick() { equeue_tick_init(); } - unsigned equeue_ms = reinterpret_cast(equeue_timer)->read_ms(); - return (equeue_minutes << 16) + equeue_ms; + unsigned minutes; + unsigned ms; + + do { + minutes = equeue_minutes; + ms = reinterpret_cast(equeue_timer)->read_ms(); + } while (minutes != equeue_minutes); + + return minutes + ms; } From 6e920fdfe9c3b78d7e3d9b76f763e808ef0cb3bd Mon Sep 17 00:00:00 2001 From: Christopher Haster Date: Thu, 16 Feb 2017 11:43:27 -0600 Subject: [PATCH 4/4] events: Increased test tolerance to +-5ms --- TESTS/events/queue/main.cpp | 2 +- TESTS/events/timing/main.cpp | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/TESTS/events/queue/main.cpp b/TESTS/events/queue/main.cpp index bdb58b6edac..f0d1c186f32 100644 --- a/TESTS/events/queue/main.cpp +++ b/TESTS/events/queue/main.cpp @@ -70,7 +70,7 @@ SIMPLE_POSTS_TEST(0) void time_func(Timer *t, int ms) { - TEST_ASSERT_INT_WITHIN(2, ms, t->read_ms()); + TEST_ASSERT_INT_WITHIN(5, ms, t->read_ms()); t->reset(); } diff --git a/TESTS/events/timing/main.cpp b/TESTS/events/timing/main.cpp index 79554e6e152..aa361d8dd28 100644 --- a/TESTS/events/timing/main.cpp +++ b/TESTS/events/timing/main.cpp @@ -93,7 +93,7 @@ void semaphore_timing_test() { int taken = timer.read_us() - start; printf("delay %dms => error %dus\r\n", delay, abs(1000*delay - taken)); - TEST_ASSERT_INT_WITHIN(2000, taken, delay * 1000); + TEST_ASSERT_INT_WITHIN(5000, taken, delay * 1000); led = !led; }