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 https://github.com/espressif/esp-serial-flasher/blob/105279cdebab82beafc51425dbfbbb9d5cbee822/src/protocol_uart.c#L97-L121

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.

[higaski]

Out of curiosity I've started flashing the hello_world example at various addresses. I've used the following partition table and gradually increased the location of the app binary.

# ESP-IDF Partition Table
# Name,   Type, SubType, Offset,    Size,   Flags
nvs,      data, nvs,     0x9000,    0x6000,
phy_init, data, phy,     0xf000,    0x1000,
factory,  app,  factory, 0x******,  1M,

This works up to 0xF00000 and stops working at 0x1000000. So everything above 16MB currently does not work.

I'll read out the written binaries later that day to see where exactly it fails.

[higaski]

Ok, so I've investigated further and used esptool to read out the binaries after flashing. From my observations everything works fine as long as one writes <16MB. Above that address things get... weird.

So for example, if I flash the following files

"flash_files" : {
    "0x0" : "bootloader/bootloader.bin",
    "0x1000000" : "hello_world.bin",
    "0x8000" : "partition_table/partition-table.bin"
}

in that very order the only correct binary after flashing is partition-table.bin. hello_world.bin is all 0xFF, so clearly there has nothing been written there. And strangely bootloader.bin also isn't correct anymore. I suspect that the library writes binaries above 16MB to 0x0 again...

For example, the very beginning of the read out location of where the bootloader should actually be contains the string "hello_world" which is the name of the app:

binaries.zip log.txt

[DNedic]

Thanks for the data, I will investigate this further.

[DNedic]

Hello @higaski , it appears the flasher stub used by esptool and other flashing tools we provide has special logic for chips of 16MB or more in size. It will take me some time probably to investigate how we can adapt esp-serial-flasher to do the same and test it.

[higaski]

Does this mean that the esptool --no-stub option currently doesn't work either? I don't want to be clever, but it seems as if all the "32mb flash workarounds" you have put into various places are now coming back to bite you. :stuck_out_tongue_closed_eyes:

[higaski]

Any updates on this? Can you please give me a time frame for when this will be addressed?

[DNedic]

Hello @higaski , thank you for the interest however we don't have an ETA for this yet.

[higaski]

Too bad because I'm sitting on a done programming application here just waiting for that fix. :grin:

Really hope you guys find time for it at some point.

[higaski]

Does this mean that the esptool --no-stub option currently doesn't work either? I don't want to be clever, but it seems as if all the "32mb flash workarounds" you have put into various places are now coming back to bite you. 😝

Just for reference and other people coming here: It doesn't.

[DNedic]

Does this mean that the esptool --no-stub option currently doesn't work either? I don't want to be clever, but it seems as if all the "32mb flash workarounds" you have put into various places are now coming back to bite you. 😝

Just for reference and other people coming here: It doesn't.

Sorry for the late confirmation, but yes it doesn't and as far as I know can't. So we need to add stub support before going forward with this.

If you can't wait, and want to contribute to help with this we are welcome to help you through the process.

[higaski]

I've peeked at the esptool source for a little while and this seems like a daunting task now...

I assume the following steps would be necessary:

1. Fix flash detection
2. Upload stub for detected processor after flash detection
3. Jump to stub(?)
4. Proceed with flashing binaries

[DNedic]

I've peeked at the esptool source for a little while and this seems like a daunting task now...

I assume the following steps would be necessary:

1. Fix flash detection
2. Upload stub for detected processor after flash detection
3. Jump to stub(?)
4. Proceed with flashing binaries

Can you elaborate on Fix flash detection? We've made flash detection match the one in esptool, are you still getting issues?

Yes, for stub use, it is uploaded to RAM, then jumped to and then there are differences in behavior that have to be accounted for in flashing code.

[dobairoland]

I think this could be done even without a flasher stub. In the case of esptool, the reason for being not supported is because flasher stub is used by default so adding support without flasher stub wasn't a priority (and not because it wasn't possible).

[higaski]

Can you elaborate on Fix flash detection? We've made flash detection match the one in esptool, are you still getting issues?

I'm sorry my bad. Yes, flash detection works now, my 32MB flash is recognized correctly.

[higaski]

What would have to be done to finally support >16MB? Are there any necessary changes to the ESP32 bootloader?

/edit This post here suggests that support for >16MB will never be implemented for the ROM bootloader.

[igrr]

@higaski Continuing the discussion at https://github.com/espressif/esp-idf/issues/8365#issuecomment-2003119377, here are some pointers about the flasher stub.

The stub source code is available in https://github.com/espressif/esptool/tree/master/flasher_stub. I think you probably don't need to build the stub from source in this particular case, and it is simpler to get the compiled stubs from https://github.com/espressif/esptool/tree/master/esptool/targets/stub_flasher. Each of the JSON files contains base64-encoded .text and .data segments, as well as their load addresses. There is also the entry point address. The flasher tool needs to upload the .text and .data segments to the correct addresses, then instruct the ROM loader to jump to the entry point.

I think what might help you is to run esptool.py read_mac with the --trace option and see the commands sent by esptool.py between Uploading stub... and Stub running... messages.

Another implementation of uploading the stub can be found in esptool-js project, in case it helps: https://github.com/espressif/esptool-js/blob/7ed57e18642088675bec01b8e34ba196d5e135af/src/esploader.ts#L1142-L1188.