Merge branch 'bugfix/esp_timer_monotonic_test' into 'master'

esp_timer: fix occasional failures in "esp_timer_get_time returns monotonic values" test

See merge request idf/esp-idf!4340

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;
 

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);
     }
 

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));