espflash icon indicating copy to clipboard operation
espflash copied to clipboard

Error: espflash::connection_failed

Open antonsterkhov opened this issue 1 year ago • 20 comments

Error

Finished dev [optimized + debuginfo] target(s) in 0.30s Running espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 [2024-03-13T20:22:15Z INFO ] Serial port: 'COM7' [2024-03-13T20:22:15Z INFO ] Connecting... Error: espflash::connection_failed

Version

PS C:\esp32v1> espflash -V espflash 3.0.0

Windows

Windows 10 Pro 22H2

Driver UART

Silicon Labs CP210x USB to UART Bridge

esptool work

Serial port COM7 Connecting....... Detecting chip type... Unsupported detection protocol, switching and trying again... Connecting... Detecting chip type... ESP32 Chip is ESP32-D0WDQ6 (revision v1.0) Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None Crystal is 40MHz MAC: c8:c9:a3:c3:73:fc Uploading stub... Running stub... Stub running... Erasing flash (this may take a while)... Chip erase completed successfully in 2.0s Hard resetting via RTS pin...

Version 2.1.0 work

antonsterkhov avatar Mar 13 '24 20:03 antonsterkhov

I don't usually use Windows, but just tried reproducing your issue, and I was able to flash my ESP32:

esp32 on  main [?] is 📦 v0.1.0 via 🦀 v1.76.0-nightly took 6s
❯ cargo r
    Finished dev [optimized + debuginfo] target(s) in 0.12s
     Running `espflash flash --monitor --no-stub target\xtensa-esp32-none-elf\debug\esp32`
[2024-03-14T08:45:05Z INFO ] Detected 2 serial ports
[2024-03-14T08:45:05Z INFO ] Ports which match a known common dev board are highlighted
[2024-03-14T08:45:05Z INFO ] Please select a port
[2024-03-14T08:45:06Z INFO ] Serial port: 'COM10'
[2024-03-14T08:45:06Z INFO ] Connecting...
Chip type:         esp32 (revision v3.0)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
MAC address:       8c:4b:14:15:a8:a4
App/part. size:    83,856/4,128,768 bytes, 2.03%
[00:00:01] [========================================]      17/17      0x1000                                                                                                                                                                                               
[00:00:00] [========================================]       1/1       0x8000                                                                                                                                                                                               
[00:00:02] [========================================]      20/20      0x10000                                                                                                                                                                                              
[2024-03-14T08:45:13Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x12 (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:7104
load:0x40078000,len:15576
load:0x40080400,len:4
ho 8 tail 4 room 4
load:0x40080404,len:3876
entry 0x4008064c
0x4008064c - esp_hal::interrupt::xtensa::vectored::get_configured_interrupts
    at C:\Users\sergi\.cargo\registry\src\index.crates.io-6f17d22bba15001f\esp-hal-0.16.1\src\interrupt\xtensa.rs:291
I (31) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (31) boot: compile time Jun  7 2023 07:48:23
I (33) boot: Multicore bootloader
I (37) boot: chip revision: v3.0
I (42) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (55) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (79) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 003f0000
I (94) boot: End of partition table
I (98) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=03014h ( 12308) map
I (111) esp_image: segment 1: paddr=0001303c vaddr=3ffb0000 size=00004h (     4) load
I (115) esp_image: segment 2: paddr=00013048 vaddr=40080000 size=015ech (  5612) load
I (126) esp_image: segment 3: paddr=0001463c vaddr=00000000 size=0b9dch ( 47580)
I (149) esp_image: segment 4: paddr=00020020 vaddr=400d0020 size=04744h ( 18244) map
I (156) boot: Loaded app from partition at offset 0x10000
I (156) boot: Disabling RNG early entropy source...
Hello world!
Loop...
Loop...
Loop...

esp32 on  main [?] is 📦 v0.1.0 via 🦀 v1.76.0-nightly took 10s
❯ espflash --version
espflash 3.0.0

It has an FTDI USB to UART bridge

SergioGasquez avatar Mar 14 '24 08:03 SergioGasquez

I think this is all due to the waiting time for a response? Since in version 2.1.0 everything is ok. Is it possible to somehow increase the time based on version 2.1.0.

antonsterkhov avatar Mar 14 '24 09:03 antonsterkhov

Can you enable debug logs? RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r

I think this is all due to the waiting time for a response? Since in version 2.1.0 everything is ok. Is it possible to somehow increase the time based on version 2.1.0

Sorry, what time are you referring to? Timeouts diff between 3.0.0 and 2.1.0: https://github.com/esp-rs/espflash/compare/v2.1.0..v3.0.0#diff-6da039671d40a74ed662a6c7179f47cf6cebb08f9111e54629b3b87b37b5dd12

SergioGasquez avatar Mar 14 '24 09:03 SergioGasquez

Also, mind sharing the devkit that you are using?

SergioGasquez avatar Mar 14 '24 09:03 SergioGasquez

Also, mind sharing the devkit that you are using?

I have my own board based on the ESP32 Wroom 32 chip

antonsterkhov avatar Mar 14 '24 09:03 antonsterkhov

Can you enable debug logs? RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r

I think this is all due to the waiting time for a response? Since in version 2.1.0 everything is ok. Is it possible to somehow increase the time based on version 2.1.0

Sorry, what time are you referring to? Timeouts diff between 3.0.0 and 2.1.0: https://github.com/esp-rs/espflash/compare/v2.1.0..v3.0.0#diff-6da039671d40a74ed662a6c7179f47cf6cebb08f9111e54629b3b87b37b5dd12

Can you answer this?

SergioGasquez avatar Mar 14 '24 10:03 SergioGasquez

I think it's here fn calc_timeout(timeout_per_mb: Duration, size: u32) -> Duration { let mb = size as f64 / 1_000_000.0; std::cmp::max( DEFAULT_TIMEOUT, FLASH_DEFLATE_END_TIMEOUT, Duration::from_millis((timeout_per_mb.as_millis() as f64 * mb) as u64), ) }

antonsterkhov avatar Mar 14 '24 13:03 antonsterkhov

I think it's here fn calc_timeout(timeout_per_mb: Duration, size: u32) -> Duration { let mb = size as f64 / 1_000_000.0; std::cmp::max( DEFAULT_TIMEOUT, FLASH_DEFLATE_END_TIMEOUT, Duration::from_millis((timeout_per_mb.as_millis() as f64 * mb) as u64), ) }

Can you try increasing that timeout and see if it solves the issue? I could create a quick branch with the timeout increased if you prefer.

Also, could you post the output of RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r?

SergioGasquez avatar Mar 14 '24 14:03 SergioGasquez

I think it's here fn calc_timeout(timeout_per_mb: Duration, size: u32) -> Duration { let mb = size as f64 / 1_000_000.0; std::cmp::max( DEFAULT_TIMEOUT, FLASH_DEFLATE_END_TIMEOUT, Duration::from_millis((timeout_per_mb.as_millis() as f64 * mb) as u64), ) }

Can you try increasing that timeout and see if it solves the issue? I could create a quick branch with the timeout increased if you prefer.

Also, could you post the output of RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r?

I can’t start logging and I don’t understand why it crashes. I think we should set it to 3 seconds instead of 10

antonsterkhov avatar Mar 14 '24 16:03 antonsterkhov

I can’t start logging and I don’t understand why it crashes.

What do you mean?

I think we should set it to 3 seconds instead of 10

But that would make it timeout even earlier. Anyway, I just made a branch with your suggested change to see if it solves the issue, mind installing espflash from it and see if it solves it:

cargo install espflash --git https://github.com/SergioGasquez/espflash --branch /fix/windows-timeout

SergioGasquez avatar Mar 14 '24 19:03 SergioGasquez

I can’t start logging and I don’t understand why it crashes.

What do you mean?

I think we should set it to 3 seconds instead of 10

But that would make it timeout even earlier. Anyway, I just made a branch with your suggested change to see if it solves the issue, mind installing espflash from it and see if it solves it:

cargo install espflash --git https://github.com/SergioGasquez/espflash --branch /fix/windows-timeout

No it didn't help

antonsterkhov avatar Mar 14 '24 21:03 antonsterkhov

To be honest, I don't have much information right now and can't reproduce the issue, I would need you to share with me debug logs (RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r)

SergioGasquez avatar Mar 15 '24 08:03 SergioGasquez

To be honest, I don't have much information right now and can't reproduce the issue, I would need you to share with me debug logs (RUST_LOG=debug espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 or RUST_LOG=debug cargo r)

} [2024-03-15T10:28:01Z DEBUG] Using Classic reset strategy with delay of 50ms [2024-03-15T10:28:01Z DEBUG] Boot Mode: 0x13 [2024-03-15T10:28:01Z DEBUG] Download Mode: false [2024-03-15T10:28:01Z DEBUG] Writing command: Sync [2024-03-15T10:28:01Z DEBUG] Writing command: Sync [2024-03-15T10:28:01Z DEBUG] Writing command: Sync [2024-03-15T10:28:01Z DEBUG] Writing command: Sync [2024-03-15T10:28:01Z DEBUG] Writing command: Sync [2024-03-15T10:28:01Z DEBUG] Failed to reset, error Connection( WrongBootMode( "0x13", ), ), retrying Error: espflash::connection_failed

antonsterkhov avatar Mar 15 '24 10:03 antonsterkhov

The initial sync might be failing, it tires 5 times (the maximum) and also bootmode is not right. Few tests:

  • Have you tried using --no-stub? espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 --no-stub or modifying the custom runner to add that flag.
  • Put the board in download mode: Hold the boot button and press the en button.
    • If you dont have such buttons since you are using custom hw, see the corresponding pins.
  • Press the boot button while you run the espflash command

SergioGasquez avatar Mar 15 '24 11:03 SergioGasquez

The initial sync might be failing, it tires 5 times (the maximum) and also bootmode is not right. Few tests:

  • Have you tried using --no-stub? espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 --no-stub or modifying the custom runner to add that flag.

  • Put the board in download mode: Hold the boot button and press the en button.

    • If you dont have such buttons since you are using custom hw, see the corresponding pins.
  • Press the boot button while you run the espflash command

I do everything according to the instructions. But as I said earlier, everything works well with version 2.1.0. The monitor loads and works. I tried to check on the M5 Atom, and I also got a loading error.

on mac m1 version 3.0.0 works

antonsterkhov avatar Mar 15 '24 13:03 antonsterkhov

Just to confirm: Have you also tried using --no-stub? espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 --no-stub or modifying the custom runner to add that flag.

SergioGasquez avatar Mar 18 '24 09:03 SergioGasquez

Just to confirm: Have you also tried using --no-stub? espflash flash --monitor target\xtensa-esp32-none-elf\debug\esp32v1 --no-stub or modifying the custom runner to add that flag.

doesn't work either

antonsterkhov avatar Mar 18 '24 11:03 antonsterkhov

Maybe we can try connecting without resetting: Can you try using -b no-reset?

SergioGasquez avatar Mar 25 '24 10:03 SergioGasquez

Maybe we can try connecting without resetting: Can you try using -b no-reset?

I tried it on the M5, it didn’t work, but my board, which didn’t require a reboot command, did.

image

antonsterkhov avatar Mar 25 '24 14:03 antonsterkhov

I think there is a reason that it does not load in version 3, on the M5 atom there is an automatic reset and boot pull, but the time is probably different compared to version 2.1 - default-reset: Uses DTR & RTS serial control lines to try to reset the chip into. Although on the M1 Mac, version 3 loads normally with default downloads.

antonsterkhov avatar Mar 25 '24 15:03 antonsterkhov