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.

diff --git a/components/esp32/esp_timer_esp32.c b/components/esp32/esp_timer_esp32.c
index d42c8cfdc62431a7761a329c4ccf28e263ef5d65..75e3a58fa545d784b44464a85929a7e442082d29 100644 (file)
--- 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 7d87d50182d68f7ac0ce82d50e35ebe8d42b1536..510bed4618bb7cacd2c6310ca1437ccd36badeb7 100644 (file)
--- 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/unity/ref_clock.c b/tools/unit-test-app/components/unity/ref_clock.c
index 94afe01bd79445302ad9a9a583f93bac3599614e..52d4f1ca3e9a15927a245e9e86f643da8eb3ffc1 100644 (file)
--- a/tools/unit-test-app/components/unity/ref_clock.c
+++ b/tools/unit-test-app/components/unity/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));