esp-rs / espflash

Serial flasher utility for Espressif SoCs and modules based on esptool.py
Apache License 2.0
471 stars 115 forks source link

2.0.0-rc.3 fails to monitor with esp32 and CONFIG_XTAL_FREQ=26 #410

Closed rodrigorc closed 1 year ago

rodrigorc commented 1 year ago

Hello.

I have an esp32 with an XTAL at 26 MHz. I have a fresh "hello-world" template, and with espflash 1.7.0 it works flawlessly out of the box, both the flash and the serial monitor.

Then I updated to 2.0.0-rc.3. If now I run the "monitor" command without re-flashing (that is with the chip flashed by 1.7.0) then it works fine.

But if I re-flash with 2.0.0-rc.3, then the "monitor" command prints:

 (63) rtc_clk_init: Possibly invalid CONFIG_XTAL_FREQ setting (40MHz). Detected 26 MHz.

And then a lot of garbage. I'm not sure if the code is running properly, as it is only a "hello-world".

I've tried to set these values in the sdkconfig.defaults, as I used to do with the old idf.py system:

CONFIG_XTAL_FREQ_26=y
CONFIG_XTAL_FREQ=26

but they didn't seem to change anything. Moreover with esp-flash 1.7.0 those options were not set and it worked ok.

SergioGasquez commented 1 year ago

Have you tried reproducing this in main branch? git install espflash https://github.com/esp-rs/espflash

rodrigorc commented 1 year ago

No, I didn't test main, doing it now...

It still fails just the same. I noticed that using screen the console is easier to read, so I have a full screen dump now, and there are a few extra hints:

[2023-05-30T18:08:18Z INFO ] Serial port: '/dev/ttyUSB0'
[2023-05-30T18:08:18Z INFO ] Connecting...  
[2023-05-30T18:08:19Z INFO ] Using flash stub
Chip type:         esp32 (revision v1.0)
Crystal frequency: 26MHz
Flash size:        8MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       24:6f:28:22:3f:94
App/part. size:    1,006,416/8,323,072 bytes, 12.09%
[00:00:01] [========================================]      16/16      0x1000                                                                                                                                                                 [00:00:00] [========================================]       1/1       0x8000                                                                                                                                                                 [00:00:57] [========================================]     588/588     0x10000                                                                                                                                                                [2023-05-30T18:09:18Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:7024
0x3fff0030 - g_ticks_per_us_app
    at ??:??
load:0x40078000,len:15400
0x40078000 - __udivmoddi4
    at ??:??
load:0x40080400,len:3816
0x40080400 - _invalid_pc_placeholder
    at ??:??
entry 0x40080648
0x40080648 - _iram_text_start
    at ??:??
W (62) rtc_clk_init: Possibly invalid CONFIG_XTAL_FREQ setting (40MHz). Detected 26 MHz.
��N��
SergioGasquez commented 1 year ago

Thanks for adding the dump! Sadly I can't reproduce the issue because I don't have an 26 MHz ESP32, do you mind sharing the name of the devkit that you are using?

Also, if you dont mind could you test using my branch and see if the issue persists:

cargo uninstall espflash
cargo install espflash --git https://github.com/SergioGasquez/espflash --branch fix/xtal-freq
rodrigorc commented 1 year ago

My devkit is a Heltec with OLED, there are a few different models, I think it is this one.

I have just updated to that branch (https://github.com/SergioGasquez/espflash?branch=fix/xtal-freq#218f5b26). First of all, I run espflash monitor to check if monitoring a program flashed with the old 1.7 version worked and it connected just fine.

Now I re-flashed a program of mine and it shows garbage just like the stock v2.0.0.

For what it is worth, the ESP32 program is working, it looks like the issue is only with the console monitor. Except that the WiFi is not working either.

I can try to do a git-bisect if you think it can be useful.

SergioGasquez commented 1 year ago

My devkit is a Heltec with OLED, there are a few different models, I think it is this one.

Thanks for sharing it!

I have just updated to that branch (https://github.com/SergioGasquez/espflash?branch=fix/xtal-freq#218f5b26). First of all, I run espflash monitor to check if monitoring a program flashed with the old 1.7 version worked and it connected just fine.

Now I re-flashed a program of mine and it shows garbage just like the stock v2.0.0.

Then we are in the same scenario as before, right?

For what it is worth, the ESP32 program is working, it looks like the issue is only with the console monitor. Except that the WiFi is not working either.

Is the code, by any chance, open source? I could try it and see if that also related with the board or some bug in the code.

I can try to do a git-bisect if you think it can be useful.

That might be really useful, I'd appreciate it.

rodrigorc commented 1 year ago

Is the code, by any chance, open source? I could try it and see if that also related with the board or some bug in the code.

There is nothing worth sharing yet. But no need, a regular hello world reproduces the issue:

$ cargo generate --git https://github.com/esp-rs/esp-idf-template cargo

I can try to do a git-bisect if you think it can be useful. That might be really useful, I'd appreciate it.

And the blame is to... 7e5e197a30a285c3fd61d4ddd6f55e207ba9f712, that changes the espflash/resources/bootloaders/esp32*-bootloader.bin files. Reverting that commit fixes the issue.

Skimming the code, now I see there is a --bootloader option. So I've taken the version of the esp32-bootloader.bin from just before the bad commit, and using the latest espflash passing that file to --bootloader and it works great!

But thinking again... how the Xpressif idf.py does it? I think that the bootloader.bin is compiled for every project, together with the freertos+idf system. So my guess is that a bootloader.bin should be build when esp-idf-sys is compiled.

And behold! There is a target/xtensa-esp32-espidf/debug/build/esp-idf-sys-10c28408ab6b06c3/out/build/bootloader/bootloader.bin just generated. I've added it to the --bootloader option and it failed again :cry:.

But then, there is a ./target/xtensa-esp32-espidf/debug/build/esp-idf-sys-10c28408ab6b06c3/out/sdkconfig with:

CONFIG_ESP32_XTAL_FREQ_40=y

that I recall was changed to the default in esp-idf a while ago.

But now I noticed that I had written my options wrong! Now I've added to sdkconfig.default:

CONFIG_ESP32_XTAL_FREQ_26=y
CONFIG_ESP32_XTAL_FREQ=26

and using the option --bootloader target/xtensa-esp32-espidf/debug/build/esp-idf-sys-10c28408ab6b06c3/out/build/bootloader/bootloader.bin works again! :smile:.

My suggested solution to this issue is twofold:

For now, as a workaround to the second point I'm using the --bootloader option.

SergioGasquez commented 1 year ago

Thanks for all your investigation! cargo-espflash already checks if esp-idf-sys is being built and reuses the bootloader from it, so cargo espflash flash should also work! But espflash does not have cargo integration, and I don't think we should add it, so we don't have an easy way of checking if esp-idf-sys is present.

I will try to investigate if there is an easy way to patch the bootloader in espflash if we detect that the XTAL frequency is 26 MHz.

rodrigorc commented 1 year ago

Ohhh! So cargo-espflash already does that, it even flashes the just-compiled partition table!

I think that the problem here was that the default esp-idf-template sets up a runner calling espflash instead of cargo espflash. I tried chaging that but it fails becuse cargo flash does not expect the name of the application in the command line.

So I deleted the runner and added:

[alias]
flash = "espflash flash --monitor"

It does not do an automatic build, I have to run cargo build && cargo flash but I'm reasonably happy now. :+1: .

I understand now that espflash should not have integration with cargo, that I is the work of cargo-espflash. But I have three humble suggestions about this:

  1. Looking around Internet there are people with this issue. Maybe there should be a FAQ somewhere about the 26MHz XTAL thing.
  2. Espressif's idf.py has an option to flash only the app, no bootloader or partition table. Maybe espflash could do that too? Hey, maybe it shouldn't even have embedded bootloaders and flash them only if given in the command line.
  3. esp-idf-template should somehow use cargo-espflash instead of espflash.

Anyway, @SergioGasquez thank you so much for your help! :bow: .

SergioGasquez commented 1 year ago

I think that the problem here was that the default esp-idf-template sets up a runner calling espflash instead of cargo espflash. I tried chaging that but it fails becuse cargo flash does not expect the name of the application in the command line.

I don't think there is a way of setting the custom runner with cargo-espflash, cargo-espflash already has the cargo integration, and it wouldn't make much sense, just run cargo espflash flash --monitor instead of cargo run.

  1. Looking around Internet there are people with this issue. Maybe there should be a FAQ somewhere about the 26MHz XTAL thing.

Do you mind sharing references to where you found these issues? I was not even aware of ESP32 had a 26MHz XTAL variant.

  1. Espressif's idf.py has an option to flash only the app, no bootloader or partition table. Maybe espflash could do that too? Hey, maybe it shouldn't even have embedded bootloaders and flash them only if given in the command line.

You need to flash a bootloader and a partition table, unless you use direct boot.

  1. esp-idf-template should somehow use cargo-espflash instead of espflash.

Again, we provide a custom runner in the template, but that does not mean you are force to use it, in cases like yours it is more convinient to use cargo-espflash instead, but it cant be used as custom runner.

I'll close the issue as there is no way for us to patch the bootloader in espflash. The current solutions are:

rodrigorc commented 1 year ago

Do you mind sharing references to where you found these issues? I was not even aware of ESP32 had a 26MHz XTAL variant.

Well, on second read, I think none of those I found were using espflash, but other flash tools, for example this issue. I looked around a lot and maybe I mixed things up a bit 🤷, sorry for the noise.

ShawnROGrady commented 1 year ago

This issue proved extremely useful to me, thank you! I had a few sparkfun esp32 things (I think this is the one have) laying around, which were mentioned in the notice of change around default XTAL frequency, and ran in to this same issue. Similarly using cargo-espflash resolved, but with the junk printed when using espflash monitor by default it did make it hard to figure out what was wrong and how to fix it.

It does sound like the 26MHz XTAL is unusual, just wanted to add a data point and suggest possibly adding some extra documentation around this if inferring the bootloader directly in espflash is not feasible for these case. The espressif getting started guides do call this out and include steps to resolve, but figuring out how to do the same with esp-rs was not obvious until I found this issue.

Apologies if this is something for another crate, this is just the first issue I found that addressed (and thankfully resolved) my problem.