esp32c6: Waiting for download _after_ flashing

t-moe commented 10 months ago

I have a esp32c6 here that I flash using the command espflash flash --monitor --flash-size 8mb --partition-table ./partitions.csv <elf>

Sometimes I have the situation that after flashing the monitor shows:

Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
Saved PC:0x4080041e
0x4080041e - get_buffer_malloc
    at /tmp/backtrace-std/.embuild/espressif/esp-idf/master/components/spi_flash/spi_flash_os_func_app.c:193
waiting for download

Why is it still waiting for download? I have not pulled the strapping pin GPIO9 to low.

I have not yet found out when this happens exactly, but it seems to somehow depend on the firmware I flash...

t-moe commented 10 months ago

Minimal example // repro:

start with an erased esp32c6 (I'm using a esp32-c6-devkit-c1 v1.2 here)
Run cargo generate esp-rs/esp-idf-template to generate a hello world with std, based on idf v5.1.
Connect the target via JTAG USB. The pins are not connected to any external components, just a naked dev kit. (hook up the uart0 pins to the logic analyzer if you like)
Flash this to the target with espflash flash --monitor <elf> (flashproblems.elf.zip )
So far everything works and the monitor prints the hello world. I can also press CTRL+R, still works
Exit the monitor (from step 4), then run espflash monitor --no-stub

espflash shows:

espflash monitor --no-stub
.... (version check with crates.io)
[2024-01-22T12:54:31Z INFO ] Serial port: '/dev/ttyACM0'
[2024-01-22T12:54:31Z INFO ] Connecting...
[2024-01-22T12:54:31Z DEBUG] Attempting flash enable with: SpiAttachParams { clk: 0, q: 0, d: 0, hd: 0, cs: 0 }
[2024-01-22T12:54:31Z DEBUG] Flash detect OK!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

Error:   × Broken pipe

Logic analyzer started before step 6:

The first bunch of messages shows:


ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0xc (SPI_FAST_FLASH_BOOT)
Saved PC:0x40802990
SPIWP:0xee
mode:DIO, clock div:2
load:0x4086c410,len:0xd48
load:0x4086e610,len:0x2d68
load:0x40875720,len:0x1800
SHA-256 comparison failed:
Calculated: 377c26481ad6ab0cce508450f353a55f4bd7eb9159aaf85fde3111071f164514
Expected: 0af544a033ab3492852b8232c904c578d5f07c9d4a423a64473f060db374ab32
Attempting to boot anyway...
entry 0x4086c410
\x1B[0;32mI (41) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader\x1B[0m
\x1B[0;32mI (42) boot: compile time Jun  7 2023 08:02:08\x1B[0m
\x1B[0;32mI (43) boot: chip revision: v0.0\x1B[0m
\x1B[0;32mI (46) boot.esp32c6: SPI Speed      : 40MHz\x1B[0m
\x1B[0;32mI (51) boot.esp32c6: SPI Mode       : DIO\x1B[0m
\x1B[0;32mI (56) boot.esp32c6: SPI Flash Size : 8MB\x1B[0m
\x1B[0;32mI (60) boot: Enabling RNG early entropy source...\x1B[0m
\x1B[0;32mI (66) boot: Partition Table:\x1B[0m
\x1B[0;32mI (69) boot: ## Label            Usage          Type ST Offset   Length\x1B[0m
\x1B[0;32mI (77) boot:  0 nvs              WiFi data        01 02 00009000 00006000\x1B[0m
\x1B[0;32mI (84) boot:  1 phy_init         RF data          01 01 0000f000 00001000\x1B[0m
\x1B[0;32mI (92) boot:  2 factory          factory app      00 00 00010000 007f0000\x1B[0m
\x1B[0;32mI (99) boot: End of partition table\x1B[0m
\x1B[0;32mI (103) esp_image: segment 0: paddr=00010020 vaddr=42000020 size=413f4h (267252) map\x1B[0m
\x1B[0;32mI (166) esp_image: segment 1: paddr=0005141c vaddr=40800000 size=06bfch ( 27644) load\x1B[0m
\x1B[0;32mI (174) esp_image: segment 2: paddr=00058020 vaddr=42048020 size=1da78h (121464) map\x1B[0m
\x1B[0;32mI (\xFFESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
Saved PC:0x4001a36e
waiting for download

then there is a 8 second delay, during which espflash says "broken pipe".
then the board boots up normally with:

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x10 (LP_WDT_SYS),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x4086c410,len:0xd48
load:0x4086e610,len:0x2d68
load:0x40875720,len:0x1800
SHA-256 comparison failed:
Calculated: 377c26481ad6ab0cce508450f353a55f4bd7eb9159aaf85fde3111071f164514
Expected: 0af544a033ab3492852b8232c904c578d5f07c9d4a423a64473f060db374ab32
Attempting to boot anyway...
entry 0x4086c410
\x1B[0;32mI (42) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader\x1B[0m
\x1B[0;32mI (43) boot: compile time Jun  7 2023 08:02:08\x1B[0m
\x1B[0;32mI (44) boot: chip revision: v0.0\x1B[0m
\x1B[0;32mI (47) boot.esp32c6: SPI Speed      : 40MHz\x1B[0m
\x1B[0;32mI (52) boot.esp32c6: SPI Mode       : DIO\x1B[0m
\x1B[0;32mI (57) boot.esp32c6: SPI Flash Size : 8MB\x1B[0m
\x1B[0;32mI (62) boot: Enabling RNG early entropy source...\x1B[0m
\x1B[0;32mI (67) boot: Partition Table:\x1B[0m
\x1B[0;32mI (71) boot: ## Label            Usage          Type ST Offset   Length\x1B[0m
\x1B[0;32mI (78) boot:  0 nvs              WiFi data        01 02 00009000 00006000\x1B[0m
\x1B[0;32mI (85) boot:  1 phy_init         RF data          01 01 0000f000 00001000\x1B[0m
\x1B[0;32mI (93) boot:  2 factory          factory app      00 00 00010000 007f0000\x1B[0m
\x1B[0;32mI (100) boot: End of partition table\x1B[0m
\x1B[0;32mI (105) esp_image: segment 0: paddr=00010020 vaddr=42000020 size=413f4h (267252) map\x1B[0m
\x1B[0;32mI (167) esp_image: segment 1: paddr=0005141c vaddr=40800000 size=06bfch ( 27644) load\x1B[0m
\x1B[0;32mI (175) esp_image: segment 2: paddr=00058020 vaddr=42048020 size=1da78h (121464) map\x1B[0m
\x1B[0;32mI (200) esp_image: segment 3: paddr=00075aa0 vaddr=40806bfc size=0193ch (  6460) load\x1B[0m
\x1B[0;32mI (207) esp_image: segment 4: paddr=000773e4 vaddr=40808540 size=00fcch (  4044) load\x1B[0m
\x1B[0;32mI (211) boot: Loaded app from partition at offset 0x10000\x1B[0m
\x1B[0;32mI (212) boot: Disabling RNG early entropy source...\x1B[0m
\x1B[0;32mI (229) cpu_start: Unicore app\x1B[0m
\x1B[0;32mI (229) cpu_start: Pro cpu up.\x1B[0m
\x1B[0;33mW (238) clk: esp_perip_clk_init() has not been implemented yet\x1B[0m
\x1B[0;32mI (244) cpu_start: Pro cpu start user code\x1B[0m
\x1B[0;32mI (244) cpu_start: cpu freq: 160000000 Hz\x1B[0m
\x1B[0;32mI (245) cpu_start: Application information:\x1B[0m
\x1B[0;32mI (247) cpu_start: Project name:     libespidf\x1B[0m
\x1B[0;32mI (252) cpu_start: App version:      1\x1B[0m
\x1B[0;32mI (257) cpu_start: Compile time:     Jan 22 2024 13:37:02\x1B[0m
\x1B[0;32mI (263) cpu_start: ELF file SHA256:  0000000000000000...\x1B[0m
\x1B[0;32mI (269) cpu_start: ESP-IDF:          v5.1\x1B[0m
\x1B[0;32mI (274) cpu_start: Min chip rev:     v0.0\x1B[0m
\x1B[0;32mI (278) cpu_start: Max chip rev:     v0.99 \x1B[0m
\x1B[0;32mI (283) cpu_start: Chip rev:         v0.0\x1B[0m
\x1B[0;32mI (288) heap_init: Initializing. RAM available for dynamic allocation:\x1B[0m
\x1B[0;32mI (295) heap_init: At 4080A430 len 000721E0 (456 KiB): D/IRAM\x1B[0m
\x1B[0;32mI (301) heap_init: At 4087C610 len 00002F54 (11 KiB): STACK/DIRAM\x1B[0m
\x1B[0;32mI (308) heap_init: At 50000010 len 00003FF0 (15 KiB): RTCRAM\x1B[0m
\x1B[0;32mI (315) spi_flash: detected chip: generic\x1B[0m
\x1B[0;32mI (319) spi_flash: flash io: dio\x1B[0m
\x1B[0;33mW (323) timer_group: legacy driver is deprecated, please migrate to `driver/gptimer.h`\x1B[0m
\x1B[0;32mI (335) sleep: Configure to isolate all GPIO pins in sleep state\x1B[0m
\x1B[0;32mI (339) sleep: Enable automatic switching of GPIO sleep configuration\x1B[0m
\x1B[0;32mI (346) coexist: coex firmware version: ebddf30\x1B[0m
\x1B[0;32mI (351) coexist: coexist rom version 5b8dcfa\x1B[0m
\x1B[0;32mI (356) app_start: Starting scheduler on CPU0\x1B[0m
\x1B[0;32mI (361) main_task: Started on CPU0\x1B[0m
\x1B[0;32mI (361) main_task: Calling app_main()\x1B[0m
\x1B[0;32mI (361) flashproblems: Hello, world!\x1B[0m
\x1B[0;32mI (371) main_task: Returned from app_main()\x1B[0m

If I'm doing espflash monitor (using stub), I don't get the broken pipe, but the target also hangs at "waiting for download" (it does not reset after 8 seconds though)

I'm on ubuntu 22.04 and I'm using espflash 2.1.0 (although it is the same with espflash from git (master))

t-moe commented 10 months ago

I've also tried to use the esp idf provided bootloader, e.g. flash with espflash flash --bootloader target/riscv32imac-esp-espidf/debug/build/esp-idf-sys-7af63acd3e33c9a6/out/build/bootloader/bootloader.bin --monitor target/riscv32imac-esp-espidf/debug/flashproblems

for v5.1.1: same problem. for v5.2-beta2: same problem.

EDIT:

power cycling the board does not help.
but using idf.py monitor (from idf master branch) instead of espflash monitor works.
I've tried this with two different boards.
Connecting to the target via Uart (Silabs converter in between), does also not fix this.
(I'm not connect to a USB hub. the target is directly attached to my laptop)
Using a esp-hal based (no-std) example, does also not work

SergioGasquez commented 10 months ago

Just tried reproducing the error and I was not able to reproduce it:

t-moe commented 10 months ago

Thanks for trying to reproduce this @SergioGasquez . I can also not reproduce this reliably. There are times where this issue occurs constantly and then there are times where it does not occur for hours/days. I'll keep this issue open for a while and try to add more info, as soon as the issue occurs again.

t-moe commented 10 months ago

At least in this case here, it is not the cable: I've just had another occurrence with a new chip + new cable.

The fact that idf.py monitor works in this case, hints that this is some sort of timing issue...

SergioGasquez commented 10 months ago

Just as an experiment, could you try the following?

cargo install espflash --git https://github.com/SergioGasquez/espflash --branch feat/reset-args
espflash monitor --before no-reset-no-sync --chip esp32c6

csgordon commented 10 months ago

I'm just dropping in here to say I have seen what seems to be the same issue with my new esp32c6. With a fresh minimal esp-template project:

$ cargo run
    Finished dev [unoptimized + debuginfo] target(s) in 0.39s
     Running `espflash flash --monitor target/riscv32imac-unknown-none-elf/debug/exp3`
[2024-01-31T18:43:17Z INFO ] Detected 6 serial ports
[2024-01-31T18:43:17Z INFO ] Ports which match a known common dev board are highlighted
[2024-01-31T18:43:17Z INFO ] Please select a port
✔ Remember this serial port for future use? · no
[2024-01-31T18:43:19Z INFO ] Serial port: '/dev/cu.usbmodem141401'
[2024-01-31T18:43:19Z INFO ] Connecting...
[2024-01-31T18:43:20Z INFO ] Using flash stub
Chip type:         esp32c6 (revision v0.0)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi 6, BT 5
MAC address:       40:4c:ca:4e:6a:28
App/part. size:    202,480/8,323,072 bytes, 2.43%
[00:00:00] [========================================]      13/13      0x0
[00:00:00] [========================================]       1/1       0x8000
[00:00:01] [========================================]      79/79      0x10000                                                                                                      [2024-01-31T18:43:21Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
Saved PC:0x408007fe
0x408007fe - core::option::Option<T>::unwrap
    at /Users/<user>/.rustup/toolchains/nightly-x86_64-apple-darwin/lib/rustlib/src/rust/library/core/src/option.rs:929
waiting for download

I don't have time right this moment, but I wanted to chime in and say there's at least one other occurrence. It looks like I should investigate updating the firmware and I'll try the suggested experiment, but I probably won't get to those until tomorrow.

MabezDev commented 10 months ago

I have seen this too, to reproduce my case:

1) Manually put the chip into download mode, hold boot whilst resetting the chip 2) flash it with espflash 3) Observe the rom download mode message

csgordon commented 10 months ago

Part of me was wondering if this might be a tooling configuration issue (until today I had not gotten any Rust to run on an esp32c6), and wondered if there was some weirdness in my macos setup. But it seems to not be the case.

My experience above was with a Waveshare ESP32-C6-DEV-KIT-N8, which is a custom package around a ESP32-C6-WROOM-1. It still exhibits this issue.

However, 20 minutes ago I received a delivery of a proper Espressif ESP32-C6-DevKitC-1, which also uses the ESP32-C6-WROOM-1. I popped it out of the box, plugged it in, ran cargo run, and it worked perfectly:

$ cargo run
    Finished dev [unoptimized + debuginfo] target(s) in 7.03s
     Running `espflash flash --monitor target/riscv32imac-unknown-none-elf/debug/exp3`
[2024-02-01T21:08:07Z INFO ] Detected 4 serial ports
[2024-02-01T21:08:07Z INFO ] Ports which match a known common dev board are highlighted
[2024-02-01T21:08:07Z INFO ] Please select a port
[2024-02-01T21:08:15Z INFO ] Serial port: '/dev/cu.usbserial-1410'
[2024-02-01T21:08:15Z INFO ] Connecting...
[2024-02-01T21:08:15Z INFO ] Using flash stub
Chip type:         esp32c6 (revision v0.0)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi 6, BT 5
MAC address:       40:4c:ca:51:39:7c
App/part. size:    202,480/8,323,072 bytes, 2.43%
[00:00:01] [========================================]      13/13      0x0
[00:00:00] [========================================]       1/1       0x8000
[00:00:07] [========================================]      79/79      0x10000                                                                                                      [2024-02-01T21:08:25Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x4086c410,len:0xd48
0x4086c410 - _ESP_HAL_DEVICE_PERIPHERALS
    at ??:??
load:0x4086e610,len:0x2d68
0x4086e610 - _ESP_HAL_DEVICE_PERIPHERALS
    at ??:??
load:0x40875720,len:0x1800
0x40875720 - _ESP_HAL_DEVICE_PERIPHERALS
    at ??:??
SHA-256 comparison failed:
Calculated: 377c26481ad6ab0cce508450f353a55f4bd7eb9159aaf85fde3111071f164514
Expected: 0af544a033ab3492852b8232c904c578d5f07c9d4a423a64473f060db374ab32
Attempting to boot anyway...
entry 0x4086c410
0x4086c410 - _ESP_HAL_DEVICE_PERIPHERALS
    at ??:??
I (42) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (42) boot: compile time Jun  7 2023 08:02:08
I (43) boot: chip revision: v0.0
I (47) boot.esp32c6: SPI Speed      : 40MHz
I (52) boot.esp32c6: SPI Mode       : DIO
I (57) boot.esp32c6: SPI Flash Size : 8MB
I (61) boot: Enabling RNG early entropy source...
I (67) boot: Partition Table:
I (70) boot: ## Label            Usage          Type ST Offset   Length
I (78) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (85) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (92) boot:  2 factory          factory app      00 00 00010000 007f0000
I (100) boot: End of partition table
I (104) esp_image: segment 0: paddr=00010020 vaddr=42000020 size=28ab4h (166580) map
I (147) esp_image: segment 1: paddr=00038adc vaddr=40800000 size=0001ch (    28) load
I (147) esp_image: segment 2: paddr=00038b00 vaddr=42028b00 size=078f4h ( 30964) map
I (159) esp_image: segment 3: paddr=000403fc vaddr=4080001c size=012c4h (  4804) load
I (162) boot: Loaded app from partition at offset 0x10000
I (167) boot: Disabling RNG early entropy source...
INFO - Logger is setup
Hello world!
Loop...
Loop...
Loop...
Loop...
<you get the idea>

My new (working) board has the same ESP-ROM and Build date as the one that doesn't work.

For completeness, I'll mention that the espflash board-info reports the exact same for both boards aside from the MAC (below happens to be for the Espressif kit):

$ espflash board-info
[2024-02-01T21:10:43Z INFO ] Detected 4 serial ports
[2024-02-01T21:10:43Z INFO ] Ports which match a known common dev board are highlighted
[2024-02-01T21:10:43Z INFO ] Please select a port
[2024-02-01T21:10:45Z INFO ] Serial port: '/dev/cu.usbserial-1410'
[2024-02-01T21:10:45Z INFO ] Connecting...
[2024-02-01T21:10:45Z INFO ] Using flash stub
Chip type:         esp32c6 (revision v0.0)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi 6, BT 5
MAC address:       ...

t-moe commented 10 months ago

I dont think this is hardware related. I had the issue occur with various boards (also different types) and then again it does not appear for days on the exact same hardware. Also, if I remember correctly, idf.py monitor always works, even if espflash monitor fails.

This looks like some timing issue to me...

Without having looked at the source, I imagine there is a memory location or register which tells the first stage bootloader to stay in bootloader mode after reset and do not continue with the normal boot process (so that you can send more commands to it). Can it be that theres old data in this location/register? Just guessing here...

t-moe commented 9 months ago

Just as an experiment, could you try the following?

cargo install espflash --git https://github.com/SergioGasquez/espflash --branch feat/reset-args
espflash monitor --before no-reset-no-sync --chip esp32c6

RUST_LOG=debug espflash flash --monitor target/riscv32imac-unknown-none-elf/debug/esp32_hw_3_0  --before no-reset-no-sync --chip esp32c6
...(Debug messages of crates.io version checking ommited)
[2024-02-05T16:31:24Z WARN ] Pre-connection option 'NoResetNoSync' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-02-05T16:31:24Z INFO ] Serial port: '/dev/ttyACM0'
[2024-02-05T16:31:24Z INFO ] Connecting...
[2024-02-05T16:31:24Z DEBUG] Writing command: ReadReg { address: 1611335768 }
Error: espflash::timeout

  × Error while connecting to device
  ╰─▶ Timeout while running ReadReg command

Vollbrecht commented 9 months ago

does this timeout behavior persist after a cold boot? I also saw it multiple times with current HEAD, even after cold boot, i could only got the timeout cleared by manually forcing it into download mode, but not via cold boot, indicating that it didn't reset the esp correctly after a attach.

t-moe commented 9 months ago

Yes, the issue persists over unplug/replug until I manually put the device into download mode.

SergioGasquez commented 9 months ago

Tried reproducing the issue with @MabezDev steps and using espflash@3.0.0-rc.1:

Manually put the chip into download mode, hold boot whilst resetting the chip


esp32c6 on  main [?] is 📦 v0.1.0 via 🦀 v1.78.0-nightly
❯ espflash monitor --before no-reset-no-sync --chip esp32c6
[2024-02-20T14:56:44Z WARN ] Pre-connection option 'NoResetNoSync' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-02-20T14:56:44Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-02-20T14:56:44Z INFO ] Connecting...
Commands:
CTRL+R    Reset chip
CTRL+C    Exit

Loop... Loop... ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x1 (POWERON),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO)) waiting for download

> 2. flash it with espflash
> 3. Observe the rom download mode message

esp32c6 on  main [?] is 📦 v0.1.0 via 🦀 v1.78.0-nightly took 6s ❯ cargo r Finished dev [unoptimized + debuginfo] target(s) in 0.02s Running espflash flash --monitor target/riscv32imac-unknown-none-elf/debug/esp32c6 [2024-02-20T14:57:00Z INFO ] Serial port: '/dev/ttyUSB0' [2024-02-20T14:57:00Z INFO ] Connecting... [2024-02-20T14:57:01Z INFO ] Using flash stub [2024-02-20T14:57:02Z WARN ] Setting baud rate higher than 115,200 can cause issues Chip type: esp32c6 (revision v0.0) Crystal frequency: 40 MHz Flash size: 8MB Features: WiFi 6, BT 5 MAC address: 60:55:f9:f7:1b:6c App/part. size: 172,384/4,128,768 bytes, 4.18% [2024-02-20T14:57:02Z INFO ] Flashing has completed! Commands: CTRL+R Reset chip CTRL+C Exit

ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:2 load:0x4086c410,len:0xd48 load:0x4086e610,len:0x2d68 load:0x40875720,len:0x1800 entry 0x4086c410 I (23) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader I (24) boot: compile time Jun 7 2023 08:02:08 I (25) boot: chip revision: v0.0 I (29) boot.esp32c6: SPI Speed : 40MHz I (33) boot.esp32c6: SPI Mode : DIO I (38) boot.esp32c6: SPI Flash Size : 4MB I (43) boot: Enabling RNG early entropy source... I (49) boot: Partition Table: I (52) boot: ## Label Usage Type ST Offset Length I (59) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (67) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (74) boot: 2 factory factory app 00 00 00010000 003f0000 I (82) boot: End of partition table I (86) esp_image: segment 0: paddr=00010020 vaddr=42000020 size=22dd0h (142800) map I (123) esp_image: segment 1: paddr=00032df8 vaddr=40808000 size=00020h ( 32) load I (124) esp_image: segment 2: paddr=00032e20 vaddr=42022e20 size=06044h ( 24644) map I (134) esp_image: segment 3: paddr=00038e6c vaddr=40808020 size=012c4h ( 4804) load I (139) boot: Loaded app from partition at offset 0x10000 I (144) boot: Disabling RNG early entropy source... Hello world! Loop... Loop...

Vollbrecht commented 9 months ago

@SergioGasquez the initial issue was about the usb/jtag connection not the uart one. There might be differences here how this is influencing it

MabezDev commented 9 months ago

Yes sorry I should have been more clear, I've only seen it happen with USB jtag.

SergioGasquez commented 9 months ago

Oh! Completely forgot that “small” detail.

Manually put the chip into download mode, hold boot whilst resetting the chip

Loop...
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x1 (POWERON),boot:0x67 (DOWNLOAD(USB/UART0/SDIO_REI_REO))
waiting for download

flash it with espflash

Observe the rom download mode message


esp32c6 on  main [?] is 📦 v0.1.0 via 🦀 v1.78.0-nightly took 9s
❯ cargo r
Finished dev [unoptimized + debuginfo] target(s) in 0.02s
Running `espflash flash --monitor target/riscv32imac-unknown-none-elf/debug/esp32c6`
[2024-02-20T15:32:41Z INFO ] Serial port: '/dev/ttyACM0'
[2024-02-20T15:32:41Z INFO ] Connecting...
[2024-02-20T15:32:41Z INFO ] Using flash stub
[2024-02-20T15:32:41Z WARN ] Setting baud rate higher than 115,200 can cause issues
Chip type:         esp32c6 (revision v0.0)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi 6, BT 5
MAC address:       60:55:f9:f7:1b:6c
App/part. size:    172,384/4,128,768 bytes, 4.18%
[2024-02-20T15:32:41Z INFO ] Flashing has completed!
Commands:
CTRL+R    Reset chip
CTRL+C    Exit

ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x15 (USB_UART_HPSYS),boot:0x67 (DOWNLOAD(USB/UART0/SDIO_REI_REO)) Saved PC:0x4080042e waiting for download

UART port shows:

ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x15 (USB_UART_HPSYS),boot:0x67 (DOWNLOAD(USB/UART0/SDIO_REI_REO)) Saved PC:0x40017600 waiting for download ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x15 (USB_UART_HPSYS),boot:0x67 (DOWNLOAD(USB/UART0/SDIO_REI_REO)) Saved PC:0x4080042e waiting for download ``` Edit: Today, I tried again reproducing the error and `rst` and `boot` values are different, now they are the same as in the OP: ``` ❯ cargo r ... [2024-02-21T11:17:21Z INFO ] Flashing has completed! Commands: CTRL+R Reset chip CTRL+C Exit ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO)) Saved PC:0x4080042e waiting for download ``` Edit2: Also reproduced it on H2, so looks like a general USB Jtag Serial issue

tvijverb commented 9 months ago

Same issue here with hello-world esp32c3 ESP32C3 was connected to the pc with boot pin enabled.

esp32c3-hal 0.15.0 espflash 2.1.0 and 3.0.0-rc1 reproducable example project: https://github.com/tvijverb/esp32c3-hello-world

Using older versions of esp-backtrace and esp-println seems to fix the issue.

    Finished `release` profile [optimized] target(s) in 0.04s
     Running `espflash flash --monitor target/riscv32imc-unknown-none-elf/release/hello_world`
[2024-02-21T11:27:11Z INFO ] Serial port: '/dev/ttyACM0'
[2024-02-21T11:27:11Z INFO ] Connecting...
[2024-02-21T11:27:11Z INFO ] Using flash stub
Chip type:         esp32c3 (revision v0.4)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BLE
MAC address:       34:85:18:05:bf:44
App/part. size:    81,952/4,128,768 bytes, 1.98%
[00:00:00] [========================================]      13/13      0x0                                                                                                                        [2024-02-21T11:27:12Z INFO ] Segment at address '0x8000' has not changed, skipping write
[00:00:00] [========================================]      15/15      0x10000                                                                                                                    [2024-02-21T11:27:13Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x0 (USB_BOOT)
Saved PC:0x403804a2
0x403804a2 - _start_trap_rust_hal
    at ??:??
wait usb download

SergioGasquez commented 9 months ago

I've also managed to reproduce this behavior with esptool.

Manually put the chip into download mode, hold boot whilst resetting the chip:

...
I (283) main_task: Started on CPU0
I (283) main_task: Calling app_main()
Hello world!
This is esp32c6 chip with 1 CPU core(s), WiFi/BLE, 802.15.4 (Zigbee/Thread), silicon revision v0.0, 2MB external flash
Minimum free heap size: 473304 bytes
Restarting in 10 seconds...
Restarting in 9 seconds...
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x1 (POWERON),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
waiting for download

Flash it with espflash

Observe the rom download mode message


…ples/get-started/hello_world (11eaf41) via △ v3.24.0 via 🐍 v3.11.7 took 7s
❯ idf.py -p /dev/ttyACM0 flash monitor
Executing action: flash
Running ninja in directory /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/examples/get-started/hello_world/build
Executing "ninja flash"...
[1/5] cd /home/sergio/Documents/Espre...ted/hello_world/build/hello_world.bin
hello_world.bin binary size 0x22c30 bytes. Smallest app partition is 0x100000 bytes. 0xdd3d0 bytes (86%) free.
[1/1] cd /home/sergio/Documents/Espre...world/build/bootloader/bootloader.bin
Bootloader binary size 0x5440 bytes. 0x2bc0 bytes (34%) free.
[2/3] cd /home/sergio/Documents/Espre...ents/esptool_py/run_serial_tool.cmake
esptool.py --chip esp32c6 -p /dev/ttyACM0 -b 460800 --before=default_reset --after=hard_reset write_flash --flash_mode dio --flash_freq 80m --flash_size 2MB 0x0 bootloader/bootloader.bin 0x10000 hello_world.bin 0x8000 partition_table/partition-table.bin
esptool.py v4.7.0
Serial port /dev/ttyACM0
Connecting...
Chip is ESP32-C6 (QFN40) (revision v0.0)
Features: WiFi 6, BT 5, IEEE802.15.4
Crystal is 40MHz
MAC: 60:55:f9:00:00:f7:1b:6c
BASE MAC: 60:55:f9:f7:1b:6c
MAC_EXT: 00:00
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 460800
Changed.
Configuring flash size...
Flash will be erased from 0x00000000 to 0x00005fff...
Flash will be erased from 0x00010000 to 0x00032fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Compressed 21568 bytes to 12983...
Writing at 0x00000000... (100 %)
Wrote 21568 bytes (12983 compressed) at 0x00000000 in 0.2 seconds (effective 710.9 kbit/s)...
Hash of data verified.
Compressed 142384 bytes to 74629...
Writing at 0x0002eb10... (100 %)
Wrote 142384 bytes (74629 compressed) at 0x00010000 in 0.7 seconds (effective 1707.7 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 103...
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (103 compressed) at 0x00008000 in 0.0 seconds (effective 743.6 kbit/s)...
Hash of data verified.

Leaving... Hard resetting via RTS pin... Executing action: monitor Running idf_monitor in directory /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/examples/get-started/hello_world Executing "/home/sergio/.espressif/python_env/idf5.2_py3.11_env/bin/python /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/tools/idf_monitor.py -p /dev/ttyACM0 -b 115200 --toolchain-prefix riscv32-esp-elf- --target esp32c6 --revision 0 --decode-panic backtrace /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/examples/get-started/hello_world/build/hello_world.elf -m '/home/sergio/.espressif/python_env/idf5.2_py3.11_env/bin/python' '/home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/tools/idf.py' '-p' '/dev/ttyACM0'"... --- esp-idf-monitor 1.4.0 on /dev/ttyACM0 115200 --- --- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H --- ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO)) Saved PC:0x40017604 0x40017604: ets_delay_us in ROM

waiting for download

SergioGasquez commented 9 months ago

If I flash with espflashand then run idf.py monitor, I still get the same output:

…ples/get-started/hello_world (11eaf41) via △ v3.24.0 via 🐍 v3.11.7 took 3s
❯ idf.py -p /dev/ttyACM0 monitor
Executing action: monitor
Running idf_monitor in directory /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/examples/get-started/hello_world
Executing "/home/sergio/.espressif/python_env/idf5.2_py3.11_env/bin/python /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/tools/idf_monitor.py -p /dev/ttyACM0 -b 115200 --toolchain-prefix riscv32-esp-elf- --target esp32c6 --revision 0 --decode-panic backtrace /home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/examples/get-started/hello_world/build/hello_world.elf -m '/home/sergio/.espressif/python_env/idf5.2_py3.11_env/bin/python' '/home/sergio/Documents/Espressif/espressif/esp-idf_v5.2/tools/idf.py' '-p' '/dev/ttyACM0'"...
--- esp-idf-monitor 1.4.0 on /dev/ttyACM0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
Saved PC:0x40017600
0x40017600: ets_delay_us in ROM

waiting for download

Which is strange because @t-moe mentioned:

but using idf.py monitor (from idf master branch) instead of espflash monitor works.

t-moe commented 9 months ago

The repro steps that Mabez mentioned are not the ones I initially used when first observing the bug.

If I manually put the device into bootloader mode, yes, this also occurs. But this is a different bug? (And you said it does also occur with idf.py monitor)

My initial steps are these: https://github.com/esp-rs/espflash/issues/556#issuecomment-1903964659

If I run these steps now with espflash 3.0.0-rc.1 I can't reproduce the bug. Also not with espflash 2.1.0.

But seemingly appearing at random, suddenly these steps ^^ do trigger the bug, repeatedly. I cannot tell why and when :( When the bug does occur, idf.py monitor does still work, in contrast to espflash monitor.

I havent seen the bug appearing lately, but I'll update the issue as soon as I observe it again...

Vollbrecht commented 8 months ago

I again today got the problem, running with RUST_LOG=debug espflash monitor didnt bring anything new to the table. But as soon as i run it only with espflash monitor --no-stub i at least could connect again and then could ctrl + r to reset and start normally. So the timeout happens when trying to write the stub on espflash monitor and than it will put the board in a non working state with espflash.

t-moe commented 8 months ago

I'll try to capture the raw usb packets, the next time I observe this.

( https://wiki.wireshark.org/CaptureSetup/USB )

SergioGasquez commented 8 months ago

I again today got the problem, running with RUST_LOG=debug espflash monitor didnt bring anything new to the table. But as soon as i run it only with espflash monitor --no-stub i at least could connect again and then could ctrl + r to reset and start normally. So the timeout happens when trying to write the stub on espflash monitor and than it will put the board in a non working state with espflash.

Looks like the behavior described in https://github.com/esp-rs/esp-flasher-stub/issues/45

SergioGasquez commented 8 months ago

Please, when trying to reproduce in the future, use espflash v3.0.0 or greater, since the C6 stub was updated.

LinusU commented 6 months ago

I'm having this problem as well with a new Waveshare ESP32-C6-DEV-KIT-N8 board. I have not been able to see "Hello, World!" at all yet.

I'm using espflash v3.0.0.

I'm selecting the "USB JTAG_serial debug unit" when flashing, as selecting the "USB Single Serial" doesn't seem to work.

Flashing completes successfully, but the output is then stuck on "waiting for download" instead of printing "Hello, World!".

I'm using a clean template, with the only added thing being CRATE_CC_NO_DEFAULTS = "1" (see https://github.com/esp-rs/esp-idf-template/issues/174).

$ cargo run --release
    Finished `release` profile [optimized] target(s) in 0.21s
     Running `espflash flash --monitor target/riscv32imac-esp-espidf/release/esp32-airplay-demo`
[2024-05-09T17:08:35Z INFO ] Detected 4 serial ports
[2024-05-09T17:08:35Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-09T17:08:35Z INFO ] Please select a port
[2024-05-09T17:09:00Z INFO ] Serial port: '/dev/tty.usbmodem1401'
[2024-05-09T17:09:00Z INFO ] Connecting...
[2024-05-09T17:09:00Z INFO ] Using flash stub
Chip type:         esp32c6 (revision v0.0)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi 6, BT 5
MAC address:       40:4c:ca:43:a1:48
App/part. size:    332,752/4,128,768 bytes, 8.06%
[2024-05-09T17:09:00Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-09T17:09:00Z INFO ] Segment at address '0x8000' has not changed, skipping write
[2024-05-09T17:09:00Z INFO ] Segment at address '0x10000' has not changed, skipping write
[2024-05-09T17:09:01Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x15 (USB_UART_HPSYS),boot:0x4 (DOWNLOAD(USB/UART0/SDIO_FEI_FEO))
Saved PC:0x408005b4
0x408005b4 - spi_flash_cache_enabled
    at ??:??
waiting for download

Pressing CTRL+R to reset the chip seems to work, but it then stops at "waiting for download" again.

Will continue to investigate...

trinhanhtuan commented 6 months ago

I have the same "waiting for download" issue while flashing on Xiao ESP32s3. After a day, I can work well with the following command. Let try and see if it works for you: (they key is --before & --after)

espflash flash --list-all-ports --before usb-reset --after hard-reset --monitor --chip esp32s3 --flash-size 8mb target/xtensa-esp32s3-none-elf/release/the_no-std_elf_file

Hope that useful, Trinh Tuan

bitmagier commented 6 months ago

Same issue here with ESP32H2 WROOM-03 (espflash v3.0.0) using minimal connections for USB flash (IO9 pulled down, D+, D-, 3.3V, GND).

Running `espflash flash --monitor target/riscv32imac-esp-espidf/debug/floor-light`
[2024-05-25T16:02:41Z INFO ] Serial port: '/dev/ttyACM0'
[2024-05-25T16:02:41Z INFO ] Connecting...
[2024-05-25T16:02:42Z INFO ] Using flash stub
Chip type:         esp32h2 (revision v0.1)
Crystal frequency: 32 MHz
Flash size:        2MB
Features:          BLE
MAC address:       74:4d:bd:61:6f:e8
App/part. size:    559,504/4,128,768 bytes, 13.55%
[2024-05-25T16:02:42Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-25T16:02:42Z INFO ] Segment at address '0x8000' has not changed, skipping write
[00:00:05] [========================================]     268/268     0x10000                                           [2024-05-25T16:02:49Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32h2-20221101
Build:Nov  1 2022
rst:0x15 (USB_UART_HPSYS),boot:0x0 (USB_BOOT)
Saved PC:0x408005b6
0x408005b6 - i2c_ll_read_rxfifo
    at /home/bitmagier/Workspace/opensource-me/floor-light/code/.embuild/espressif/esp-idf/v5.1.2/components/hal/esp32h2/include/hal/i2c_ll.h:587
wait usb download

Vollbrecht commented 6 months ago

@bitmagier did you try the the different -b and -a options like mention previously? you can run espflash flash help to get a list of the possible params

bitmagier commented 6 months ago

@bitmagier did you try the the different -b and -a options like mention previously? you can run espflash flash help to get a list of the possible params

Just tried - there is no positive effect.

(Doing the same flash on the development board works just fine)

BTW: I'm wondering if my PIN configuration is really sufficient. Specifically GPIO8 - for "joint boot mode" according to spec it should be pulled UP (default is floating), but there is no GPIO8 exposed on this module.

bitmagier commented 6 months ago

Yeah – I believe my issue is caused by a missing hardware reset button wired to EN to properly enable the Join Download Boot Mode. Thanks for your attention.

esp-rs / espflash

esp32c6: Waiting for download _after_ flashing #556