[Resolved] Writing to flash is faster when flash encryption is enabled??

[GerryTitan]

Hi all,

I am trying to run some benchmarks on the ESP32 to see how flash encryption affects performance. I am using esp_partition_write to write to an OTA partition, which, to my knowledge, will transparently encrypt the contents of write buffer when flash encryption is enabled. Based on this post, I was led to believe that writing to encrypted flash in this matter would cause some noticeable slowdown. You can see the code below for reference.

Code: Select all

void write_flash()
{

	int64_t beginT, endT;
	char data[32];
	memset(data, 'x', sizeof(data));

	const esp_partition_t* partition = esp_partition_find_first(ESP_PARTITION_TYPE_APP, ESP_PARTITION_SUBTYPE_ANY, "ota_0");

	beginT = esp_timer_get_time();
	for(int i = 0; i < RUNS; i++)
	{
		esp_partition_erase_range(partition, i, sizeof(data));
		esp_partition_write(partition, i, data, sizeof(data));
	}
	endT = esp_timer_get_time();
	printf("%lld\n", endT - beginT);
}

I ran this 10000 times with both flash encryption enabled and disabled. When I ran it without flash encryption, it took about 12.89 seconds. When I enabled flash encryption, it only took 0.4 seconds.

Does anybody have an explanation? I am truly at a loss here. I have tested this multiple times with several different partitions. I tried writing 512 bytes instead of 32 bytes. However, the results are consistent. I also checked to make sure esp_partition_write returns ESP_OK, and it does.

I am using ESP-IDF v4.0-rc-10-g08219f3cf.

[ESP_igrr]

Can you try checking the error codes returned from esp_partition_erase_range and esp_partition_write? Does the operation actually succeed?

[GerryTitan]

Can you try checking the error codes returned from esp_partition_erase_range and esp_partition_write? Does the operation actually succeed?

Seems the erase operation was failing before. I moved it to outside the for loop and had it erase the whole partition. Now both the erase and write operations return ESP_OK. Same results as before.

[ESP_igrr]

The following slightly modified code snippet runs in 35 seconds both with encryption enabled and disabled:

Code: Select all

static void example_read_write_flash(void)
{
    const esp_partition_t* partition = esp_partition_find_first(
        ESP_PARTITION_TYPE_DATA, ESP_PARTITION_SUBTYPE_ANY, "storage");
    assert(partition);
    const int RUNS = 1000;
    int64_t beginT, endT;
    char data[32];
    esp_fill_random(data, sizeof(data));
    
    beginT = esp_timer_get_time();
    for(int i = 0; i < RUNS; i++) {
        ESP_ERROR_CHECK(esp_partition_erase_range(partition, 0, SPI_FLASH_SEC_SIZE));
        ESP_ERROR_CHECK(esp_partition_write(partition, 0, data, sizeof(data)));
    }
    endT = esp_timer_get_time();
    printf("%lld\n", endT - beginT);
}

There are a few of changes here:
1. pass zero offset to partition_write, since encrypted writes must be 16-byte aligned
2. pass correct erase size to partition_erase_range (minimum erase size is one sector)
3. fill the buffer with random numbers — this prevents the compiler from optimizing out the `memset` and placing the buffer into .rodata. Since .rodata is in Flash, the flash writing code needs to take a different (slower) code path. In practice you will most often be writing to flash from RAM, not from flash.

[GerryTitan]

Okay, after making the changes you suggest, now the non-encrypted chip runs in 49 seconds, while the encrypted chip runs in 43 seconds. Certainly less of a discrepancy than before, but it still doesn't explain why flash encrypted writes are faster.

For the record, both chips are the ESP32-WROOM-32 and the only difference in their configuration is that the secure chip has secure boot and flash encryption enabled.

I wonder if my eFuse configuration is affecting the write speed somehow? I'll attach a screenshot.

[ESP_igrr]

This might be due to slightly different erase times. This benchmark, as written, is mainly measuring the flash sector erase time, which is much larger than the time required to write 32 bytes. Typically the sector erase time varies from clone flash chip to another, and also may increase as the flash wears out. You can try creating two data partitions (one encrypted, one uneencrypted) and running the test with both on the same chip. If you are interested in measuring write performance, then the benchmark probably needs to be adjusted to write the entire sector (4k bytes) per erase operation.

[ESP_Angus]

This might be due to slightly different erase times. This benchmark, as written, is mainly measuring the flash sector erase time, which is much larger than the time required to write 32 bytes. Typically the sector erase time varies from clone flash chip to another, and also may increase as the flash wears out. You can try creating two data partitions (one encrypted, one uneencrypted) and running the test with both on the same chip. If you are interested in measuring write performance, then the benchmark probably needs to be adjusted to write the entire sector (4k bytes) per erase operation.

Just FWIW, erase times can also vary based on the contents of the specific sector and (I think) the wearing of individual sectors. So even two partitions on the same flash could exhibit slightly different erase times.

So I'd suggest going with Igrr's second suggestion, or rewriting the benchmark to only measure the write time (as the erase will be the same command sent to the flash regardless of whether it's encrypted or not), but there should be minimal "flash chip" timing variations for writes - any variation there is due to encryption overhead (or reverse-overhead).

[GerryTitan]

Here is the new code. I generated two data partitions, one encrypted and the other plaintext. I made sure not to measure the erase time, as you can see below. Encrypted writes took 0.34 seconds, plaintext writes took 1.17 seconds.

I also tried this with a 512-byte payload. In that case, encrypted writes took 0.24 seconds, while plaintext writes took 8.49 seconds.

I have done this on 2 different chips, with identical results.

Code: Select all

void write_flash()
{
	int64_t beginT, endT, totalT;
	char data[32];
	esp_fill_random(data, sizeof(data));

	const esp_partition_t* encrypted_part = esp_partition_find_first(ESP_PARTITION_TYPE_DATA, 
		ESP_PARTITION_SUBTYPE_ANY, "storage1");
	const esp_partition_t* plaintext_part = esp_partition_find_first(ESP_PARTITION_TYPE_DATA,
		ESP_PARTITION_SUBTYPE_ANY, "storage2");
	assert(encrypted_part);
	assert(plaintext_part);

	totalT = 0;
	for(int i = 0; i < RUNS; i++)
	{
		ESP_ERROR_CHECK(esp_partition_erase_range(encrypted_part, 0, encrypted_part->size));
		beginT = esp_timer_get_time();
		ESP_ERROR_CHECK(esp_partition_write(encrypted_part, 0, data, sizeof(data)));
		endT = esp_timer_get_time();
		totalT += (endT - beginT);
		vTaskDelay(10 / portTICK_PERIOD_MS);
	}
	printf("Encrypted writes: %lld\n", totalT);

	totalT = 0;
	for(int i = 0; i < RUNS; i++)
	{
		ESP_ERROR_CHECK(esp_partition_erase_range(plaintext_part, 0, plaintext_part->size));
		beginT = esp_timer_get_time();
		ESP_ERROR_CHECK(esp_partition_write(plaintext_part, 0, data, sizeof(data)));
		endT = esp_timer_get_time();
		totalT += (endT - beginT);
		vTaskDelay(10 / portTICK_PERIOD_MS);
	}
	printf("Plaintext writes: %lld\n", totalT);
}

[ESP_michael]

Hi GerryTitan,
Sorry for missing this. I think we have fixed this issue here: https://github.com/espressif/esp-idf/co ... 6bf9ea93ec.
Could you please take a look to see whether it's fixed? There are also fixes for 4.0 and 4.1 on their latest commit

Michael

Here is the new code. I generated two data partitions, one encrypted and the other plaintext. I made sure not to measure the erase time, as you can see below. Encrypted writes took 0.34 seconds, plaintext writes took 1.17 seconds.

I also tried this with a 512-byte payload. In that case, encrypted writes took 0.24 seconds, while plaintext writes took 8.49 seconds.

I have done this on 2 different chips, with identical results.

Code: Select all

void write_flash()
{
	int64_t beginT, endT, totalT;
	char data[32];
	esp_fill_random(data, sizeof(data));

	const esp_partition_t* encrypted_part = esp_partition_find_first(ESP_PARTITION_TYPE_DATA, 
		ESP_PARTITION_SUBTYPE_ANY, "storage1");
	const esp_partition_t* plaintext_part = esp_partition_find_first(ESP_PARTITION_TYPE_DATA,
		ESP_PARTITION_SUBTYPE_ANY, "storage2");
	assert(encrypted_part);
	assert(plaintext_part);

	totalT = 0;
	for(int i = 0; i < RUNS; i++)
	{
		ESP_ERROR_CHECK(esp_partition_erase_range(encrypted_part, 0, encrypted_part->size));
		beginT = esp_timer_get_time();
		ESP_ERROR_CHECK(esp_partition_write(encrypted_part, 0, data, sizeof(data)));
		endT = esp_timer_get_time();
		totalT += (endT - beginT);
		vTaskDelay(10 / portTICK_PERIOD_MS);
	}
	printf("Encrypted writes: %lld\n", totalT);

	totalT = 0;
	for(int i = 0; i < RUNS; i++)
	{
		ESP_ERROR_CHECK(esp_partition_erase_range(plaintext_part, 0, plaintext_part->size));
		beginT = esp_timer_get_time();
		ESP_ERROR_CHECK(esp_partition_write(plaintext_part, 0, data, sizeof(data)));
		endT = esp_timer_get_time();
		totalT += (endT - beginT);
		vTaskDelay(10 / portTICK_PERIOD_MS);
	}
	printf("Plaintext writes: %lld\n", totalT);
}

[ESP_michael]

Issue closed. Please feel free to reopen it if the issue still exist.