Writing >= 16MB addresses not working (ESF-106)

[higaski]

Port

USER_DEFINED

Target chip

ESP32-S3

Hardware Configuration

Custom ESP32-S3 board connected via USB CDC

Log output

Found 2 serial ports
Connecting to ttyACM0
Found esp32s3
Flash will be erased from 0x0 to 0x5fff
Flash size detection failed, falling back to default
Writing at 0x400... (4%)
Writing at 0xc00... (14%)
Writing at 0x1400... (23%)
Writing at 0x1c00... (33%)
Writing at 0x2400... (42%)
Writing at 0x2c00... (52%)
Writing at 0x3400... (61%)
Writing at 0x3c00... (71%)
Writing at 0x4400... (80%)
Writing at 0x4c00... (90%)
Flash will be erased from 0x10000 to 0x164fff
Flash size detection failed, falling back to default
Writing at 0x10400... (0%)
Writing at 0x32400... (10%)
Writing at 0x54400... (20%)
Writing at 0x76400... (30%)
Writing at 0x98400... (40%)
Writing at 0xba400... (50%)
Writing at 0xdc400... (60%)
Writing at 0xfe400... (70%)
Writing at 0x120400... (80%)
Writing at 0x142800... (90%)
Writing at 0x1644e0... (100%)
Flash will be erased from 0x1010000 to 0x1ffffff
Flash size detection failed, falling back to default
Error: 
COMMAND_FAILED


Erasing flash failed (ESP_LOADER_ERROR_INVALID_RESPONSE)
Cannot connect to target (ESP_LOADER_ERROR_INVALID_RESPONSE)

More Information

I've written a small native CLI/GUI application much like the Espressif Flash Download Tool to make downloading multiple binaries easier. So far I've tested this app with the hello_world example on various Espressif demo boards. Uploading the example (consisting of bootloader, app and partition table) works flawlessly.

Thinking that my app works I've moved on to trying to flash my current project on a custom ESP32-S3 board. The projects flash files are

"flash_files" : {
    "0x0" : "bootloader/bootloader.bin",
    "0x10000" : "WULF.bin",
    "0x8000" : "partition_table/partition-table.bin",
    "0xa000" : "ota_data_initial.bin",
    "0x1010000" : "storage.bin",
    "0x810000" : "nvs.bin"
}

As you can probably guess some of those binaries are bigger than the hello_world example

# ESP-IDF Partition Table
# Name,   Type, SubType, Offset,  Size, Flags
phy_init, data, phy,     ,        4K,
otadata,  data, ota,     ,        8K,
ota_0,    app,  ota_0,   ,        4M,
ota_1,    app,  ota_1,   ,        4M,
nvs,      data, nvs,     ,        8M,
storage,  data, spiffs,  ,        16320K,

Uploading those bigger binaries does not work. I'm getting the following output from the library (see full log above)

Error: 
COMMAND_FAILED

I assume that for some reason the library can't handle certain memory region or binary sizes (yet)?
This might also be related to #23?
Any suggestions? Is this a known issue?

[DNedic]

Hello @higaski , we do not know of any limitation that would cause flashing some memory regions to fail. Can you please provide either a log with SERIAL_FLASHER_DEBUG_TRACE set or a logic analyzer trace to help us narrow down the issue?

[higaski]

How should SERIAL_FLASHER_DEBUG_TRACE help in this case? This define seems to be used in the ports code only, nowhere in the actual lib. I've implemented loader_port_debug_print() though, shouldn't this be sufficient? I think the log I've added already contains the debug outputs (e.g. the one about flash size).

Also none of your examples writes larger binaries at higher adresses. Could you maybe add one?

[DNedic]

I apologize, I have assumed you have implemented debug tracing in the same way as it is implemented in other ports. In that case either copy over the tracing from other ports to your port and enable it, or provide a logic analyzer trace.

Also none of your examples writes larger binaries at higher adresses. Could you maybe add one?

Thanks for the suggestion, we will explore the idea!

[higaski]

Oh I'm sorry now I got it. I thought the macro enables loader_port_debug_print, but it actually enables transfer_debug_print.

I'll provide logs tomorrow.

[DNedic]

Unification of logging/tracing is something we are looking into for the future, but it requires quite extensive changes.

[higaski]

I've added the logging. Here is a log of me trying to write the storage.bin file mentioned above

--- WRITE ---
c0 00 08 24 00 00 00 00 00 07 07 12 20 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 c0 
--- READ ---
45 53 50 2d 52 4f 4d 3a 65 73 70 33 32 73 33 2d 32 30 32 31 30 33 32 37 0d 0a 42 75 69 6c 64 3a 4d 61 72 20 32 37 20 32 30 32 31 0d 0a 72 73 74 3a 30 78 31 20 28 50 4f 57 45 52 4f 4e 29 2c 62 6f 6f 74 3a 30 78 31 30 20 28 44 4f 57 4e 4c 4f 41 44 28 55 53 42 2f 55 41 52 54 30 29 29 0d 0a 77 61 69 74 69 6e 67 20 66 6f 72 20 64 6f 77 6e 6c 6f 61 64 0d 0a 
--- WRITE ---
c0 00 08 24 00 00 00 00 00 07 07 12 20 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 55 c0 
--- READ ---
c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 c0 01 08 04 00 07 07 12 20 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 00 10 00 40 c0 
--- READ ---
c0 01 0a 04 00 09 00 00 00 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 48 70 00 60 c0 
--- READ ---
c0 01 0a 04 00 12 f4 00 00 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 4c 70 00 60 c0 
--- READ ---
c0 01 0a 04 00 00 00 00 00 00 00 00 00 c0 
--- WRITE ---
c0 00 0d 08 00 00 00 00 00 00 00 00 00 00 00 00 00 c0 
--- READ ---
c0 01 0d 04 00 00 00 00 00 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 18 20 00 60 c0 
--- READ ---
c0 01 0a 04 00 00 00 00 80 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 20 20 00 60 c0 
--- READ ---
c0 01 0a 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 28 20 00 60 17 00 00 00 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 18 20 00 60 00 00 00 90 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 20 20 00 60 9f 00 00 70 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 58 20 00 60 00 00 00 00 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 00 20 00 60 00 00 04 00 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 00 00 00 70 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 00 20 00 60 c0 
--- READ ---
c0 01 0a 04 00 00 00 00 00 00 00 00 00 c0 
--- WRITE ---
c0 00 0a 04 00 00 00 00 00 58 20 00 60 c0 
--- READ ---
c0 01 0a 04 00 c2 80 39 00 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 18 20 00 60 00 00 00 80 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 c2 80 39 00 00 00 00 00 c0 
--- WRITE ---
c0 00 09 10 00 00 00 00 00 20 20 00 60 00 00 00 70 ff ff ff ff 00 00 00 00 c0 
--- READ ---
c0 01 09 04 00 c2 80 39 00 00 00 00 00 c0 
--- WRITE ---
c0 00 02 14 00 00 00 00 00 00 00 ff 00 db dc 3f 00 00 00 04 00 00 00 00 01 01 00 00 00 00 c0 
--- READ ---
c0 01 02 04 00 c2 80 39 00 01 06 00 00 c0 

I'm getting shut down in line 121 of check_response

esp-serial-flasher/src/protocol_uart.c

Lines 97 to 121 in 105279c

	static esp_loader_error_t check_response(command_t cmd, uint32_t *reg_value, void *resp, uint32_t resp_size)
	{
	esp_loader_error_t err;
	common_response_t *response = (common_response_t *)resp;
	do {
	err = SLIP_receive_packet(resp, resp_size);
	if (err != ESP_LOADER_SUCCESS) {
	return err;
	}
	} while ((response->direction != READ_DIRECTION) || (response->command != cmd));
	response_status_t *status = (response_status_t *)((uint8_t *)resp + resp_size - sizeof(response_status_t));
	if (status->failed) {
	log_loader_internal_error(status->error);
	return ESP_LOADER_ERROR_INVALID_RESPONSE;
	}
	if (reg_value != NULL) {
	*reg_value = response->value;
	}
	return ESP_LOADER_SUCCESS;
	}

Here is the call stack at this point

libflasher.so!check_response(command_t cmd, uint32_t * reg_value, void * resp, uint32_t resp_size)
libflasher.so!send_cmd(const void * cmd_data, uint32_t size, uint32_t * reg_value)
libflasher.so!loader_flash_begin_cmd(uint32_t offset, uint32_t erase_size, uint32_t block_size, uint32_t blocks_to_write, _Bool encryption)
libflasher.so!esp_loader_flash_start(uint32_t offset, uint32_t image_size, uint32_t block_size)

This is the command being sent

[DNedic]

Thanks for the data, after looking into this in the ROM, I don't see any reason it would fail, however it is possible that the default hardcoded params used by loader_spi_parameters() are incorrect for the specific flash chip: https://github.com/espressif/esp-serial-flasher/blob/master/src/protocol_common.c#L280

Can you compare the parameters of the flash chip used on your board to these?

[higaski]

I'm using a ESP32-S3-WROOM-2-N32R8V module. Do they come with different flash chips?
I've just looked at the datasheet and couldn't find any specifics on the flash. Where can I find that info?

I don't think that this is the issue though. Flashing generally seems to work. I can write the hello_world example just fine. I assume that this also wouldn't work if the flash parameters would be wrong?

/edit
Oh I see, it falls back to some default flash size which is most likely smaller than 32MB...?
Why does detect_flash_size fail though?

[DNedic]

Good spot, it seems that is the reason loader_spi_parameters() sends wrong info. I will investigate this, in the meantime, try manually setting the parameters for your flash chip and trying to flash that way.

[higaski]

I've manually set the flash size to 32MB, but this doesn't cut it. I can now flash the project, but it's giving me an "invalid header" error after reboot.

Is there anything else beside flash size I might need to set?

[DNedic]

Did you successfully manage to flash the same exact binaries with esptool or other flashing tools we provide and get the app to work?

[higaski]

Flashing with the idf.py frontend works yes.

[DNedic]

Have you enabled the MD5 checks? Also, can you read back the contents of the flash flashed with esp-serial-flasher using esptool, and contents of the flash written with esptool so we can see the difference?

[higaski]

I haven't gotten MD5 to work yet. Even on examples which work it keeps telling me that my MD5 checks fail. Haven't looked into this further.

For the esptool, yes, I'll try that tomorrow.