From d3724dc35d938cd19a84e39803fe30d7c9fca92c Mon Sep 17 00:00:00 2001 From: Ivan Grokhotkov Date: Fri, 22 Feb 2019 21:27:43 +0800 Subject: [PATCH] esp_timer: fix occasional failures in "monotonic values" test 1. ref_clock used in unit tests occasionally produces time off by ~100 microseconds shortly after being started. Add a delay to let ref_clock stabilise, until the cause is found. 2. Reduce roundoff error accumulation which would occasionally cause the test to fail, by choosing an overflow value which can be divided by APB frequency. 3. Move time sampling part of the test into an IRAM function to reduce variations due to cache behavior. 4. Remove calculation of "standard deviation" in the test, as what was calculated was not actually standard deviation, and it did not add any useful information. --- components/esp32/esp_timer_esp32.c | 4 +-- components/esp32/test/test_esp_timer.c | 35 ++++++++++--------- .../components/test_utils/ref_clock.c | 2 ++ 3 files changed, 23 insertions(+), 18 deletions(-) diff --git a/components/esp32/esp_timer_esp32.c b/components/esp32/esp_timer_esp32.c index d42c8cfdc..75e3a58fa 100644 --- a/components/esp32/esp_timer_esp32.c +++ b/components/esp32/esp_timer_esp32.c @@ -97,7 +97,7 @@ static uint32_t s_alarm_overflow_val = DEFAULT_ALARM_OVERFLOW_VAL; static const char* TAG = "esp_timer_impl"; -// Interrupt handle retuned by the interrupt allocator +// Interrupt handle returned by the interrupt allocator static intr_handle_t s_timer_interrupt_handle; // Function from the upper layer to be called when the interrupt happens. @@ -123,7 +123,7 @@ static uint32_t s_timer_us_per_overflow; // value than the one which caused an interrupt. This can cause interrupt handler // to consider that the interrupt has happened due to timer overflow, incrementing // s_time_base_us. To avoid this, frequency switch hook sets this flag if -// it needs to set timer alarm value to ALARM_OVERFLOW_VAL. Interrupt hanler +// it needs to set timer alarm value to ALARM_OVERFLOW_VAL. Interrupt handler // will not increment s_time_base_us if this flag is set. static bool s_mask_overflow; diff --git a/components/esp32/test/test_esp_timer.c b/components/esp32/test/test_esp_timer.c index 7d87d5018..510bed461 100644 --- a/components/esp32/test/test_esp_timer.c +++ b/components/esp32/test/test_esp_timer.c @@ -24,7 +24,12 @@ static uint32_t s_old_overflow_val; static void setup_overflow() { s_old_overflow_val = esp_timer_impl_get_overflow_val(); - esp_timer_impl_set_overflow_val(0x7fffff); /* overflow every ~0.1 sec */} + /* Overflow every 0.1 sec. + * Chosen so that it is 0 modulo s_timer_ticks_per_us (which is 80), + * to prevent roundoff error on each overflow. + */ + esp_timer_impl_set_overflow_val(8000000); +} static void teardown_overflow() { @@ -404,6 +409,13 @@ TEST_CASE("esp_timer_get_time call takes less than 1us", "[esp_timer]") TEST_PERFORMANCE_LESS_THAN(ESP_TIMER_GET_TIME_PER_CALL, "%dns", ns_per_call); } +static int64_t IRAM_ATTR __attribute__((noinline)) get_clock_diff() +{ + uint64_t hs_time = esp_timer_get_time(); + uint64_t ref_time = ref_clock_get(); + return hs_time - ref_time; +} + TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer]") { typedef struct { @@ -411,7 +423,6 @@ TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer]") bool pass; int test_cnt; int error_cnt; - int64_t total_sq_error; int64_t max_error; int64_t avg_diff; int64_t dummy; @@ -422,27 +433,21 @@ TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer]") state->pass = true; /* make sure both functions are in cache */ - state->dummy = esp_timer_get_time(); - state->dummy += ref_clock_get(); + state->dummy = get_clock_diff(); /* calculate the difference between the two clocks */ portDISABLE_INTERRUPTS(); - int64_t hs_start_time = esp_timer_get_time(); - int64_t start_time = ref_clock_get(); + int64_t delta = get_clock_diff(); portENABLE_INTERRUPTS(); - int64_t delta = hs_start_time - start_time; - - int64_t now = start_time; + int64_t start_time = ref_clock_get(); int error_repeat_cnt = 0; - while (now - start_time < 10000000) { /* 10 seconds */ + while (ref_clock_get() - start_time < 10000000) { /* 10 seconds */ /* Get values of both clocks again, and check that they are close to 'delta'. * We don't disable interrupts here, because esp_timer_get_time doesn't lock * interrupts internally, so we check if it can get "broken" by a well placed * interrupt. */ - int64_t hs_now = esp_timer_get_time(); - now = ref_clock_get(); - int64_t diff = hs_now - (now + delta); + int64_t diff = get_clock_diff() - delta; /* Allow some difference due to rtos tick interrupting task between * getting 'hs_now' and 'now'. */ @@ -459,7 +464,6 @@ TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer]") state->avg_diff += diff; state->max_error = MAX(state->max_error, abs(diff)); state->test_cnt++; - state->total_sq_error += diff * diff; } state->avg_diff /= state->test_cnt; xSemaphoreGive(state->done); @@ -478,10 +482,9 @@ TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer]") for (int i = 0; i < portNUM_PROCESSORS; ++i) { TEST_ASSERT_TRUE( xSemaphoreTake(done, portMAX_DELAY) ); - printf("CPU%d: %s test_cnt=%d error_cnt=%d std_error=%d avg_diff=%d |max_error|=%d\n", + printf("CPU%d: %s test_cnt=%d error_cnt=%d avg_diff=%d |max_error|=%d\n", i, states[i].pass ? "PASS" : "FAIL", states[i].test_cnt, states[i].error_cnt, - (int) sqrt(states[i].total_sq_error / states[i].test_cnt), (int) states[i].avg_diff, (int) states[i].max_error); } diff --git a/tools/unit-test-app/components/test_utils/ref_clock.c b/tools/unit-test-app/components/test_utils/ref_clock.c index 94afe01bd..52d4f1ca3 100644 --- a/tools/unit-test-app/components/test_utils/ref_clock.c +++ b/tools/unit-test-app/components/test_utils/ref_clock.c @@ -119,6 +119,8 @@ void ref_clock_init() PCNT.ctrl.val |= BIT(REF_CLOCK_PCNT_UNIT * 2); PCNT.ctrl.val &= ~BIT(REF_CLOCK_PCNT_UNIT * 2); + ets_delay_us(10000); + // Enable interrupt s_milliseconds = 0; ESP_ERROR_CHECK(esp_intr_alloc(ETS_PCNT_INTR_SOURCE, ESP_INTR_FLAG_IRAM, pcnt_isr, NULL, &s_intr_handle));