diff --git a/components/spi_flash/test/test_esp_flash.c b/components/spi_flash/test/test_esp_flash.c index 774104e4d3..2e2e64e410 100644 --- a/components/spi_flash/test/test_esp_flash.c +++ b/components/spi_flash/test/test_esp_flash.c @@ -460,7 +460,7 @@ static void test_toggle_qe(esp_flash_t* chip) ESP_LOGW(TAG, "cannot clear QE bit for known permanent QE (Winbond) chips."); } else { ESP_LOGE(TAG, "cannot clear QE bit, please make sure force clearing QE option is enabled in `spi_flash_common_set_io_mode`, and this chip is not a permanent QE one."); - } + } chip->read_mode = io_mode_before; return; } @@ -610,6 +610,138 @@ static void test_write_large_buffer(esp_flash_t *chip, const uint8_t *source, si read_and_check(chip, part, source, length); } +typedef struct { + uint32_t us_start; + size_t len; + const char* name; +} time_meas_ctx_t; + +static void time_measure_start(time_meas_ctx_t* ctx) +{ + ctx->us_start = esp_timer_get_time(); +} + +static uint32_t time_measure_end(time_meas_ctx_t* ctx) +{ + uint32_t time_us = esp_timer_get_time() - ctx->us_start; + + ESP_LOGI(TAG, "%s: typical: %.2lf kB/s", ctx->name, ctx->len / (time_us/1000.)); + return ctx->len * 1000 / (time_us / 1000); +} + +#define TEST_TIMES 20 +#define TEST_SECTORS 4 + +static uint32_t measure_erase(const esp_partition_t* part) +{ + const int total_len = SPI_FLASH_SEC_SIZE * TEST_SECTORS; + time_meas_ctx_t time_ctx = {.name = "erase", .len = total_len}; + + time_measure_start(&time_ctx); + esp_err_t err = esp_flash_erase_region(part->flash_chip, part->address, total_len); + TEST_ESP_OK(err); + return time_measure_end(&time_ctx); +} + +// should called after measure_erase +static uint32_t measure_write(const char* name, const esp_partition_t* part, const uint8_t* data_to_write, int seg_len) +{ + const int total_len = SPI_FLASH_SEC_SIZE; + time_meas_ctx_t time_ctx = {.name = name, .len = total_len * TEST_TIMES}; + + time_measure_start(&time_ctx); + for (int i = 0; i < TEST_TIMES; i ++) { + // Erase one time, but write 100 times the same data + size_t len = total_len; + int offset = 0; + + while (len) { + int len_write = MIN(seg_len, len); + esp_err_t err = esp_flash_write(part->flash_chip, data_to_write + offset, part->address + offset, len_write); + TEST_ESP_OK(err); + + offset += len_write; + len -= len_write; + } + } + return time_measure_end(&time_ctx); +} + +static uint32_t measure_read(const char* name, const esp_partition_t* part, uint8_t* data_read, int seg_len) +{ + const int total_len = SPI_FLASH_SEC_SIZE; + time_meas_ctx_t time_ctx = {.name = name, .len = total_len * TEST_TIMES}; + + time_measure_start(&time_ctx); + for (int i = 0; i < TEST_TIMES; i ++) { + size_t len = total_len; + int offset = 0; + + while (len) { + int len_read = MIN(seg_len, len); + esp_err_t err = esp_flash_read(part->flash_chip, data_read + offset, part->address + offset, len_read); + TEST_ESP_OK(err); + + offset += len_read; + len -= len_read; + } + } + return time_measure_end(&time_ctx); +} + +#define MEAS_WRITE(n) (measure_write("write in "#n"-byte chunks", &test_part, data_to_write, n)) +#define MEAS_READ(n) (measure_read("read in "#n"-byte chunks", &test_part, data_read, n)) + +static void test_flash_read_write_performance(esp_flash_t* chip) +{ + const esp_partition_t *part = get_test_data_partition(); + // Copy to new partition variable and replace the chip member + // Actually there's no "partition" in the external flash on runners. We just don't bother creating a new partition variable. + esp_partition_t test_part; + memcpy(&test_part, part, sizeof(esp_partition_t)); + test_part.flash_chip = chip; + + const int total_len = SPI_FLASH_SEC_SIZE; + uint8_t *data_to_write = heap_caps_malloc(total_len, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); + uint8_t *data_read = heap_caps_malloc(total_len, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); + + srand(777); + for (int i = 0; i < total_len; i++) { + data_to_write[i] = rand(); + } + + uint32_t erase_1 = measure_erase(&test_part); + uint32_t speed_WR_4B = MEAS_WRITE(4); + uint32_t speed_RD_4B = MEAS_READ(4); + uint32_t erase_2 = measure_erase(&test_part); + uint32_t speed_WR_2KB = MEAS_WRITE(2048); + uint32_t speed_RD_2KB = MEAS_READ(2048); + + TEST_ASSERT_EQUAL_HEX8_ARRAY(data_to_write, data_read, total_len); + +// Not actually checking in this version +#define CHECK_DATA(bus, suffix) ((void)speed_##suffix) +#define CHECK_ERASE(bus, var) ((void)var) + +// Erase time may vary a lot, can increase threshold if this fails with a reasonable speed +#define CHECK_PERFORMANCE(bus) do {\ + CHECK_DATA(bus, WR_4B); \ + CHECK_DATA(bus, RD_4B); \ + CHECK_DATA(bus, WR_2KB); \ + CHECK_DATA(bus, RD_2KB); \ + CHECK_ERASE(bus, erase_1); \ + CHECK_ERASE(bus, erase_2); \ + } while (0) + + CHECK_PERFORMANCE(0); + free(data_to_write); + free(data_read); +} + +FLASH_TEST_CASE("Test esp_flash read/write performance", test_flash_read_write_performance); +FLASH_TEST_CASE_3("Test esp_flash read/write performance", test_flash_read_write_performance); + + #ifdef CONFIG_SPIRAM_USE_MALLOC /* Utility: Read into a small internal RAM buffer using esp_flash_read() and compare what @@ -676,5 +808,4 @@ static void test_flash_read_large_psram_buffer_low_internal_mem(esp_flash_t *chi FLASH_TEST_CASE("esp_flash_read large PSRAM buffer low memory", test_flash_read_large_psram_buffer_low_internal_mem); - #endif diff --git a/components/spi_flash/test/test_spi_flash.c b/components/spi_flash/test/test_spi_flash.c index 0010f86d83..0180d3bdab 100644 --- a/components/spi_flash/test/test_spi_flash.c +++ b/components/spi_flash/test/test_spi_flash.c @@ -1,4 +1,5 @@ #include +#include #include #include #include @@ -9,6 +10,7 @@ #include "driver/timer.h" #include "esp_intr_alloc.h" #include "test_utils.h" +#include "esp_log.h" struct flash_test_ctx { uint32_t offset; @@ -16,6 +18,8 @@ struct flash_test_ctx { SemaphoreHandle_t done; }; +static const char TAG[] = "test_spi_flash"; + static void flash_test_task(void *arg) { struct flash_test_ctx *ctx = (struct flash_test_ctx *) arg; @@ -168,6 +172,128 @@ TEST_CASE("spi flash functions can run along with IRAM interrupts", "[spi_flash] free(read_arg.buf); } +typedef struct { + uint32_t us_start; + size_t len; + const char* name; +} time_meas_ctx_t; + +static void time_measure_start(time_meas_ctx_t* ctx) +{ + ctx->us_start = esp_timer_get_time(); +} + +static uint32_t time_measure_end(time_meas_ctx_t* ctx) +{ + uint32_t time_us = esp_timer_get_time() - ctx->us_start; + + ESP_LOGI(TAG, "%s: typical: %.2lf kB/s", ctx->name, ctx->len / (time_us/1000.)); + return ctx->len * 1000 / (time_us / 1000); +} + +#define TEST_TIMES 20 +#define TEST_SECTORS 4 + +static uint32_t measure_erase(const esp_partition_t* part) +{ + const int total_len = SPI_FLASH_SEC_SIZE * TEST_SECTORS; + time_meas_ctx_t time_ctx = {.name = "erase", .len = total_len}; + + time_measure_start(&time_ctx); + esp_err_t err = spi_flash_erase_range(part->address, total_len); + TEST_ESP_OK(err); + return time_measure_end(&time_ctx); +} + +// should called after measure_erase +static uint32_t measure_write(const char* name, const esp_partition_t* part, const uint8_t* data_to_write, int seg_len) +{ + const int total_len = SPI_FLASH_SEC_SIZE; + time_meas_ctx_t time_ctx = {.name = name, .len = total_len * TEST_TIMES}; + + time_measure_start(&time_ctx); + for (int i = 0; i < TEST_TIMES; i ++) { + // Erase one time, but write 100 times the same data + size_t len = total_len; + int offset = 0; + + while (len) { + int len_write = MIN(seg_len, len); + esp_err_t err = spi_flash_write(part->address + offset, data_to_write + offset, len_write); + TEST_ESP_OK(err); + + offset += len_write; + len -= len_write; + } + } + return time_measure_end(&time_ctx); +} + +static uint32_t measure_read(const char* name, const esp_partition_t* part, uint8_t* data_read, int seg_len) +{ + const int total_len = SPI_FLASH_SEC_SIZE; + time_meas_ctx_t time_ctx = {.name = name, .len = total_len * TEST_TIMES}; + + time_measure_start(&time_ctx); + for (int i = 0; i < TEST_TIMES; i ++) { + size_t len = total_len; + int offset = 0; + + while (len) { + int len_read = MIN(seg_len, len); + esp_err_t err = spi_flash_read(part->address + offset, data_read + offset, len_read); + TEST_ESP_OK(err); + + offset += len_read; + len -= len_read; + } + } + return time_measure_end(&time_ctx); +} + +#define MEAS_WRITE(n) (measure_write("write in "#n"-byte chunks", part, data_to_write, n)) +#define MEAS_READ(n) (measure_read("read in "#n"-byte chunks", part, data_read, n)) + +TEST_CASE("Test spi_flash read/write performance", "[spi_flash]") +{ + const esp_partition_t *part = get_test_data_partition(); + + const int total_len = SPI_FLASH_SEC_SIZE; + uint8_t *data_to_write = heap_caps_malloc(total_len, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); + uint8_t *data_read = heap_caps_malloc(total_len, MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); + + srand(777); + for (int i = 0; i < total_len; i++) { + data_to_write[i] = rand(); + } + + uint32_t erase_1 = measure_erase(part); + uint32_t speed_WR_4B = MEAS_WRITE(4); + uint32_t speed_RD_4B = MEAS_READ(4); + uint32_t erase_2 = measure_erase(part); + uint32_t speed_WR_2KB = MEAS_WRITE(2048); + uint32_t speed_RD_2KB = MEAS_READ(2048); + + TEST_ASSERT_EQUAL_HEX8_ARRAY(data_to_write, data_read, total_len); + +// Not actually checking in this version +#define CHECK_DATA(suffix) ((void)speed_##suffix) +#define CHECK_ERASE(var) ((void)var) + + CHECK_DATA(WR_4B); + CHECK_DATA(RD_4B); + CHECK_DATA(WR_2KB); + CHECK_DATA(RD_2KB); + + // Erase time may vary a lot, can increase threshold if this fails with a reasonable speed + CHECK_ERASE(erase_1); + CHECK_ERASE(erase_2); + + free(data_to_write); + free(data_read); +} + + #if portNUM_PROCESSORS > 1 TEST_CASE("spi_flash deadlock with high priority busy-waiting task", "[spi_flash][esp_flash]")