esp32: use ref_clock in esp_timer and delay tests

This commit is contained in:
Ivan Grokhotkov
2017-08-30 09:01:37 +08:00
parent 9a2c62cf2b
commit c5632d3012
2 changed files with 78 additions and 54 deletions

View File

@@ -6,17 +6,21 @@
#include "rom/ets_sys.h" #include "rom/ets_sys.h"
#include "freertos/FreeRTOS.h" #include "freertos/FreeRTOS.h"
#include "freertos/task.h" #include "freertos/task.h"
#include "freertos/semphr.h"
#include "test_utils.h"
typedef struct { typedef struct {
int delay_us; int delay_us;
int method; int method;
int result;
SemaphoreHandle_t done;
} delay_test_arg_t; } delay_test_arg_t;
static void test_delay_task(void* p) static void test_delay_task(void* p)
{ {
const delay_test_arg_t* arg = (delay_test_arg_t*) p; delay_test_arg_t* arg = (delay_test_arg_t*) p;
struct timeval tv_start, tv_stop; vTaskDelay(1);
gettimeofday(&tv_start, NULL); uint64_t start = ref_clock_get();
switch (arg->method) { switch (arg->method) {
case 0: case 0:
ets_delay_us(arg->delay_us); ets_delay_us(arg->delay_us);
@@ -27,32 +31,51 @@ static void test_delay_task(void* p)
default: default:
TEST_FAIL(); TEST_FAIL();
} }
gettimeofday(&tv_stop, NULL); uint64_t stop = ref_clock_get();
int real_delay_us = (tv_stop.tv_sec - tv_start.tv_sec) * 1000000 +
tv_stop.tv_usec - tv_start.tv_usec; arg->result = (int) (stop - start);
printf("%s core=%d expected=%d actual=%d\n", arg->method ? "vTaskDelay" : "ets_delay_us", xSemaphoreGive(arg->done);
xPortGetCoreID(), arg->delay_us, real_delay_us);
TEST_ASSERT_TRUE(abs(real_delay_us - arg->delay_us) < 1000);
vTaskDelay(1);
vTaskDelete(NULL); vTaskDelete(NULL);
} }
TEST_CASE("ets_delay produces correct delay on both CPUs", "[delay][ignore]") TEST_CASE("ets_delay produces correct delay on both CPUs", "[delay]")
{ {
int delay_ms = 50; int delay_ms = 50;
const delay_test_arg_t args = { .delay_us = delay_ms * 1000, .method = 0 }; const delay_test_arg_t args = {
.delay_us = delay_ms * 1000,
.method = 0,
.done = xSemaphoreCreateBinary()
};
ref_clock_init();
xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 0); xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 0);
vTaskDelay(delay_ms / portTICK_PERIOD_MS + 1); TEST_ASSERT( xSemaphoreTake(args.done, delay_ms * 2 / portTICK_PERIOD_MS) );
TEST_ASSERT_INT32_WITHIN(1000, args.delay_us, args.result);
xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 1); xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 1);
vTaskDelay(delay_ms / portTICK_PERIOD_MS + 1); TEST_ASSERT( xSemaphoreTake(args.done, delay_ms * 2 / portTICK_PERIOD_MS) );
TEST_ASSERT_INT32_WITHIN(1000, args.delay_us, args.result);
ref_clock_deinit();
vSemaphoreDelete(args.done);
} }
TEST_CASE("vTaskDelay produces correct delay on both CPUs", "[delay]") TEST_CASE("vTaskDelay produces correct delay on both CPUs", "[delay]")
{ {
int delay_ms = 50; int delay_ms = 50;
const delay_test_arg_t args = { .delay_us = delay_ms * 1000, .method = 1 }; const delay_test_arg_t args = {
.delay_us = delay_ms * 1000,
.method = 1,
.done = xSemaphoreCreateBinary()
};
ref_clock_init();
xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 0); xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 0);
vTaskDelay(delay_ms / portTICK_PERIOD_MS + 1); TEST_ASSERT( xSemaphoreTake(args.done, delay_ms * 2 / portTICK_PERIOD_MS) );
TEST_ASSERT_INT32_WITHIN(1000, args.delay_us, args.result);
xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 1); xTaskCreatePinnedToCore(test_delay_task, "", 2048, (void*) &args, 3, NULL, 1);
vTaskDelay(delay_ms / portTICK_PERIOD_MS + 1); TEST_ASSERT( xSemaphoreTake(args.done, delay_ms * 2 / portTICK_PERIOD_MS) );
TEST_ASSERT_INT32_WITHIN(1000, args.delay_us, args.result);
ref_clock_deinit();
vSemaphoreDelete(args.done);
} }

View File

@@ -7,6 +7,7 @@
#include "freertos/FreeRTOS.h" #include "freertos/FreeRTOS.h"
#include "freertos/task.h" #include "freertos/task.h"
#include "freertos/semphr.h" #include "freertos/semphr.h"
#include "test_utils.h"
TEST_CASE("esp_timer orders timers correctly", "[esp_timer]") TEST_CASE("esp_timer orders timers correctly", "[esp_timer]")
{ {
@@ -65,15 +66,15 @@ TEST_CASE("esp_timer produces correct delay", "[esp_timer]")
{ {
void timer_func(void* arg) void timer_func(void* arg)
{ {
struct timeval* ptv = (struct timeval*) arg; uint64_t* p_end = (uint64_t*) arg;
gettimeofday(ptv, NULL); *p_end = ref_clock_get();
} }
volatile struct timeval tv_end = {0}; uint64_t t_end;
esp_timer_handle_t timer1; esp_timer_handle_t timer1;
esp_timer_create_args_t args = { esp_timer_create_args_t args = {
.callback = &timer_func, .callback = &timer_func,
.arg = (struct timeval*) &tv_end, .arg = &t_end,
.name = "timer1" .name = "timer1"
}; };
TEST_ESP_OK(esp_timer_create(&args, &timer1)); TEST_ESP_OK(esp_timer_create(&args, &timer1));
@@ -81,21 +82,21 @@ TEST_CASE("esp_timer produces correct delay", "[esp_timer]")
const int delays_ms[] = {20, 100, 200, 250}; const int delays_ms[] = {20, 100, 200, 250};
const size_t delays_count = sizeof(delays_ms)/sizeof(delays_ms[0]); const size_t delays_count = sizeof(delays_ms)/sizeof(delays_ms[0]);
ref_clock_init();
for (size_t i = 0; i < delays_count; ++i) { for (size_t i = 0; i < delays_count; ++i) {
tv_end = (struct timeval) {0}; t_end = 0;
struct timeval tv_start; uint64_t t_start = ref_clock_get();
gettimeofday(&tv_start, NULL);
TEST_ESP_OK(esp_timer_start_once(timer1, delays_ms[i] * 1000)); TEST_ESP_OK(esp_timer_start_once(timer1, delays_ms[i] * 1000));
vTaskDelay(delays_ms[i] * 2 / portTICK_PERIOD_MS); vTaskDelay(delays_ms[i] * 2 / portTICK_PERIOD_MS);
TEST_ASSERT(tv_end.tv_sec != 0 || tv_end.tv_usec != 0); TEST_ASSERT(t_end != 0);
int32_t ms_diff = (tv_end.tv_sec - tv_start.tv_sec) * 1000 + int32_t ms_diff = (t_end - t_start) / 1000;
(tv_end.tv_usec - tv_start.tv_usec) / 1000;
printf("%d %d\n", delays_ms[i], ms_diff); printf("%d %d\n", delays_ms[i], ms_diff);
TEST_ASSERT_INT32_WITHIN(portTICK_PERIOD_MS, delays_ms[i], ms_diff); TEST_ASSERT_INT32_WITHIN(portTICK_PERIOD_MS, delays_ms[i], ms_diff);
} }
ref_clock_deinit();
TEST_ESP_OK( esp_timer_dump(stdout) ); TEST_ESP_OK( esp_timer_dump(stdout) );
@@ -111,16 +112,14 @@ TEST_CASE("periodic ets_timer produces correct delays", "[esp_timer]")
esp_timer_handle_t timer; esp_timer_handle_t timer;
size_t cur_interval; size_t cur_interval;
int intervals[NUM_INTERVALS]; int intervals[NUM_INTERVALS];
struct timeval tv_start; uint64_t t_start;
} test_args_t; } test_args_t;
void timer_func(void* arg) void timer_func(void* arg)
{ {
test_args_t* p_args = (test_args_t*) arg; test_args_t* p_args = (test_args_t*) arg;
struct timeval tv_now; uint64_t t_end = ref_clock_get();
gettimeofday(&tv_now, NULL); int32_t ms_diff = (t_end - p_args->t_start) / 1000;
int32_t ms_diff = (tv_now.tv_sec - p_args->tv_start.tv_sec) * 1000 +
(tv_now.tv_usec - p_args->tv_start.tv_usec) / 1000;
printf("timer #%d %dms\n", p_args->cur_interval, ms_diff); printf("timer #%d %dms\n", p_args->cur_interval, ms_diff);
p_args->intervals[p_args->cur_interval++] = ms_diff; p_args->intervals[p_args->cur_interval++] = ms_diff;
// Deliberately make timer handler run longer. // Deliberately make timer handler run longer.
@@ -141,9 +140,9 @@ TEST_CASE("periodic ets_timer produces correct delays", "[esp_timer]")
.name = "timer1" .name = "timer1"
}; };
TEST_ESP_OK(esp_timer_create(&create_args, &timer1)); TEST_ESP_OK(esp_timer_create(&create_args, &timer1));
ref_clock_init();
args.timer = timer1; args.timer = timer1;
gettimeofday(&args.tv_start, NULL); args.t_start = ref_clock_get();
TEST_ESP_OK(esp_timer_start_periodic(timer1, delay_ms * 1000)); TEST_ESP_OK(esp_timer_start_periodic(timer1, delay_ms * 1000));
vTaskDelay(delay_ms * (NUM_INTERVALS + 1)); vTaskDelay(delay_ms * (NUM_INTERVALS + 1));
@@ -152,7 +151,7 @@ TEST_CASE("periodic ets_timer produces correct delays", "[esp_timer]")
for (size_t i = 0; i < NUM_INTERVALS; ++i) { for (size_t i = 0; i < NUM_INTERVALS; ++i) {
TEST_ASSERT_INT32_WITHIN(portTICK_PERIOD_MS, (i + 1) * delay_ms, args.intervals[i]); TEST_ASSERT_INT32_WITHIN(portTICK_PERIOD_MS, (i + 1) * delay_ms, args.intervals[i]);
} }
ref_clock_deinit();
TEST_ESP_OK( esp_timer_dump(stdout) ); TEST_ESP_OK( esp_timer_dump(stdout) );
TEST_ESP_OK( esp_timer_delete(timer1) ); TEST_ESP_OK( esp_timer_delete(timer1) );
@@ -176,7 +175,7 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
test_common_t* common; test_common_t* common;
bool pass; bool pass;
SemaphoreHandle_t done; SemaphoreHandle_t done;
struct timeval* tv_start; uint64_t t_start;
} test_args_t; } test_args_t;
void timer_func(void* arg) void timer_func(void* arg)
@@ -185,10 +184,7 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
// check order // check order
size_t count = p_args->common->count; size_t count = p_args->common->count;
int expected_index = p_args->common->order[count]; int expected_index = p_args->common->order[count];
struct timeval tv_timer; int ms_since_start = (ref_clock_get() - p_args->t_start) / 1000;
gettimeofday(&tv_timer, NULL);
int ms_since_start = (tv_timer.tv_sec - p_args->tv_start->tv_sec) * 1000 +
(tv_timer.tv_usec - p_args->tv_start->tv_usec) / 1000;
printf("Time %dms, at count %d, expected timer %d, got timer %d\n", printf("Time %dms, at count %d, expected timer %d, got timer %d\n",
ms_since_start, count, expected_index, p_args->timer_index); ms_since_start, count, expected_index, p_args->timer_index);
if (expected_index != p_args->timer_index) { if (expected_index != p_args->timer_index) {
@@ -217,8 +213,8 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
SemaphoreHandle_t done = xSemaphoreCreateCounting(3, 0); SemaphoreHandle_t done = xSemaphoreCreateCounting(3, 0);
struct timeval tv_now; ref_clock_init();
gettimeofday(&tv_now, NULL); uint64_t now = ref_clock_get();
test_args_t args1 = { test_args_t args1 = {
.timer_index = 1, .timer_index = 1,
@@ -226,7 +222,7 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
.common = &common, .common = &common,
.pass = true, .pass = true,
.done = done, .done = done,
.tv_start = &tv_now .t_start = now
}; };
test_args_t args2 = { test_args_t args2 = {
@@ -235,7 +231,7 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
.common = &common, .common = &common,
.pass = true, .pass = true,
.done = done, .done = done,
.tv_start = &tv_now .t_start = now
}; };
test_args_t args3 = { test_args_t args3 = {
@@ -244,7 +240,7 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
.common = &common, .common = &common,
.pass = true, .pass = true,
.done = done, .done = done,
.tv_start = &tv_now .t_start = now
}; };
@@ -276,6 +272,8 @@ TEST_CASE("multiple timers are ordered correctly", "[esp_timer]")
TEST_ASSERT_TRUE(args2.pass); TEST_ASSERT_TRUE(args2.pass);
TEST_ASSERT_TRUE(args3.pass); TEST_ASSERT_TRUE(args3.pass);
ref_clock_deinit();
TEST_ESP_OK( esp_timer_dump(stdout) ); TEST_ESP_OK( esp_timer_dump(stdout) );
TEST_ESP_OK( esp_timer_delete(args1.timer) ); TEST_ESP_OK( esp_timer_delete(args1.timer) );
@@ -337,27 +335,29 @@ TEST_CASE("esp_timer_get_time call takes less than 1us", "[esp_timer]")
TEST_ASSERT(ns_per_call < 1000); TEST_ASSERT(ns_per_call < 1000);
} }
/* This test runs for about 10 minutes and is disabled in CI */ /* This test runs for about 10 minutes and is disabled in CI.
* Such run time is needed to have FRC2 timer overflow a few times.
*/
TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer][ignore]") TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer][ignore]")
{ {
void timer_test_task(void* arg) { void timer_test_task(void* arg) {
uint64_t last = esp_timer_get_time(); int64_t delta = esp_timer_get_time() - ref_clock_get();
const int iter_count = 1000000000; const int iter_count = 1000000000;
for (int i = 0; i < iter_count; ++i) { for (int i = 0; i < iter_count; ++i) {
uint64_t now = esp_timer_get_time(); uint64_t now = esp_timer_get_time();
if (now < last || now - last > 100) { uint64_t ref_now = ref_clock_get();
printf("core_id:%d now: %lld last:%lld\n", xPortGetCoreID(), now, last); int64_t diff = (int64_t) (now - ref_now) - delta;
fflush(stdout); /* Allow some difference due to rtos tick interrupting task between
abort(); * getting 'now' and 'ref_now'.
} */
last = now; TEST_ASSERT_INT32_WITHIN(100, 0, (int) diff);
} }
xSemaphoreGive((SemaphoreHandle_t) arg); xSemaphoreGive((SemaphoreHandle_t) arg);
vTaskDelete(NULL); vTaskDelete(NULL);
} }
ref_clock_init();
SemaphoreHandle_t done_1 = xSemaphoreCreateBinary(); SemaphoreHandle_t done_1 = xSemaphoreCreateBinary();
SemaphoreHandle_t done_2 = xSemaphoreCreateBinary(); SemaphoreHandle_t done_2 = xSemaphoreCreateBinary();
@@ -368,4 +368,5 @@ TEST_CASE("esp_timer_get_time returns monotonic values", "[esp_timer][ignore]")
TEST_ASSERT_TRUE( xSemaphoreTake(done_2, portMAX_DELAY) ); TEST_ASSERT_TRUE( xSemaphoreTake(done_2, portMAX_DELAY) );
vSemaphoreDelete(done_1); vSemaphoreDelete(done_1);
vSemaphoreDelete(done_2); vSemaphoreDelete(done_2);
ref_clock_deinit();
} }