search

esp-rs / espflash

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

espflash 2.0.0-rc3 fails during flashing ESP32-S3-BOX with larger image on M1, Linux and Windows #356

Closed georgik closed 1 year ago

georgik commented 1 year ago

How to simulate:

git clone --depth 1 git@github.com:slint-ui/slint.git
cd slint
cargo +esp build -p printerdemo_mcu --target xtensa-esp32s3-none-elf --no-default-features --features=mcu-board-support/esp32-s3-box --release --config examples/mcu-board-support/esp32_s3_box/cargo-config.toml
espflash flash --monitor target/xtensa-esp32s3-none-elf/release/printerdemo_mcu

Result: flashing failed in 3rd stage around 300th chunk.

[2023-02-27T06:46:05Z INFO ] Detected 6 serial ports
[2023-02-27T06:46:05Z INFO ] Ports which match a known common dev board are highlighted
[2023-02-27T06:46:05Z INFO ] Please select a port
[2023-02-27T06:46:06Z INFO ] Serial port: '/dev/cu.usbmodem11101'
[2023-02-27T06:46:06Z INFO ] Connecting...
[2023-02-27T06:46:06Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40MHz
Flash size:        16MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e1:a5:a0
App/part. size:    1,103,456/16,711,680 bytes, 6.60%
[00:00:00] [========================================]      13/13      0x0
[00:00:00] [========================================]       1/1       0x8000
Error: espflash::serial_error

  × Communication error while flashing device
  ├─▶ IO error while using serial port: Broken pipe
  ╰─▶ Broken pipe

Tests

georgik commented 1 year ago

Attaching logs from Linux with enabled Debug:

[2023-02-27T07:33:03Z DEBUG] Flash(
        FlashArgs {
            image: "target/xtensa-esp32s3-none-elf/release/printerdemo_mcu",
            connect_args: ConnectArgs {
                baud: None,
                port: Some(
                    "/dev/ttyACM0",
                ),
                no_stub: false,
            },
            flash_config_args: FlashConfigArgs {
                flash_freq: None,
                flash_mode: None,
                flash_size: None,
            },
            flash_args: FlashArgs {
                bootloader: None,
                erase_parts: None,
                erase_data_parts: None,
                format: None,
                monitor: true,
                monitor_baud: None,
                partition_table: None,
                ram: false,
            },
        },
    )
[2023-02-27T07:33:03Z DEBUG] connecting to crates.io:443 at 65.9.95.64:443
[2023-02-27T07:33:03Z DEBUG] No cached session for DnsName(DnsName(DnsName("crates.io")))
[2023-02-27T07:33:03Z DEBUG] Not resuming any session
[2023-02-27T07:33:03Z DEBUG] Using ciphersuite TLS13_AES_128_GCM_SHA256
[2023-02-27T07:33:03Z DEBUG] Not resuming
[2023-02-27T07:33:03Z DEBUG] TLS1.3 encrypted extensions: [ServerNameAck]
[2023-02-27T07:33:03Z DEBUG] ALPN protocol is None
[2023-02-27T07:33:03Z DEBUG] created stream: Stream(RustlsStream)
[2023-02-27T07:33:03Z DEBUG] sending request GET https://crates.io/api/v1/crates/espflash/versions
[2023-02-27T07:33:03Z DEBUG] writing prelude: GET /api/v1/crates/espflash/versions HTTP/1.1
    Host: crates.io
    User-Agent: ureq/2.6.2
    Accept: */*
    accept-encoding: gzip
[2023-02-27T07:33:03Z DEBUG] Ticket saved
[2023-02-27T07:33:03Z DEBUG] Chunked body in response
[2023-02-27T07:33:03Z DEBUG] response 200 to GET https://crates.io/api/v1/crates/espflash/versions
[2023-02-27T07:33:03Z DEBUG] dropping stream: Stream(RustlsStream)
[2023-02-27T07:33:03Z INFO ] Serial port: '/dev/ttyACM0'
[2023-02-27T07:33:03Z INFO ] Connecting...
[2023-02-27T07:33:04Z INFO ] Using flash stub
[2023-02-27T07:33:04Z DEBUG] Loading flash stub for chip: Esp32s3
[2023-02-27T07:33:04Z DEBUG] Write 4836 byte stub text
[2023-02-27T07:33:04Z DEBUG] Write 4 byte stub data
[2023-02-27T07:33:04Z DEBUG] Finish stub write
[2023-02-27T07:33:04Z DEBUG] Stub written!
[2023-02-27T07:33:04Z DEBUG] Re-detected chip: Esp32s3
[2023-02-27T07:33:04Z DEBUG] Attempting flash enable with: SpiAttachParams { clk: 0, q: 0, d: 0, hd: 0, cs: 0 }
[2023-02-27T07:33:04Z DEBUG] Flash detect OK!
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40MHz
Flash size:        16MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e1:a5:a0
App/part. size:    1,168,816/16,711,680 bytes, 6.99%
[00:00:00] [========================================]      13/13      0x0                                                                                                                                                       [00:00:00] [========================================]       1/1       0x8000                                                                                                                                                    Error: espflash::serial_error

  × Communication error while flashing device
  ├─▶ IO error while using serial port: Broken pipe
  ╰─▶ Broken pipe
georgik commented 1 year ago

Exact place of failure: 

[00:00:07] [======================>                 ]     253/455     0x10000   
Error: espflash::serial_error
georgik commented 1 year ago

The problem is related to a watchdog.

Issue for espflash 1.x : https://github.com/esp-rs/espflash/issues/171

Might require update of stub https://github.com/espressif/esptool/commit/32e80148493a83d34bad635287cb97e458d2af58

jessebraham commented 1 year ago

The watchdog workaround was removed because the comment above it was misleading and I was under the impression it was no longer required, we will add this back in at some point.

jnross commented 1 year ago

Thanks for spotting and reporting this. I was just about to open a similar issue. I confirmed this is a regression from commit 1c054e84127c08a3ccfa60ada39a6185ed1c9ee0, and that reverting that commit resolved it. I'm excited to see that there is a fix that will fix this by moving forward rather than bringing back an old workaround. Here is how I isolated the regression:

➜  espflash git:(main) ✗ git log --oneline -1                                                                                            
4665742 (HEAD -> main, junelife/main, esp-rs/main, esp-rs/HEAD) Make Interface constructor public
➜  espflash git:(main) ✗ cargo run flash binary --port /dev/cu.usbmodem3212201
warning: unused import: `USB_SERIAL_JTAG_PID`
  --> espflash/src/targets/flash_target/esp32.rs:11:30
   |
11 |     connection::{Connection, USB_SERIAL_JTAG_PID},
   |                              ^^^^^^^^^^^^^^^^^^^
   |
   = note: `#[warn(unused_imports)]` on by default

warning: `espflash` (lib) generated 1 warning
    Finished dev [unoptimized + debuginfo] target(s) in 0.09s
     Running `/Users/joe/src/espflash/target/debug/espflash flash binary --port /dev/cu.usbmodem3212201`
[2023-03-02T20:13:00Z INFO ] Serial port: '/dev/cu.usbmodem3212201'
[2023-03-02T20:13:00Z INFO ] Connecting...
[2023-03-02T20:13:00Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e2:4f:f8
App/part. size:    1,157,008/8,323,072 bytes, 13.90%
[00:00:00] [========================================]      13/13      0x0                                                                                           [00:00:00] [========================================]       1/1       0x8000                                                                                        Error: espflash::serial_error

  × Communication error while flashing device
  ├─▶ IO error while using serial port: Broken pipe
  ╰─▶ Broken pipe

➜  espflash git:(main) ✗ git revert 1c054e84127c08a3ccfa60ada39a6185ed1c9ee0
[main 222d0cf] Revert "Remove the USB Serial JTAG watchdog workaround now that we use the stub"
 1 file changed, 43 insertions(+)
➜  espflash git:(main) ✗ cargo run flash binary --port /dev/cu.usbmodem3212201
   Compiling espflash v2.0.0-rc.3 (/Users/joe/src/espflash/espflash)
    Finished dev [unoptimized + debuginfo] target(s) in 1.37s
     Running `/Users/joe/src/espflash/target/debug/espflash flash binary --port /dev/cu.usbmodem3212201`
[2023-03-02T20:13:37Z INFO ] Serial port: '/dev/cu.usbmodem3212201'
[2023-03-02T20:13:37Z INFO ] Connecting...
[2023-03-02T20:13:37Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e2:4f:f8
App/part. size:    1,157,008/8,323,072 bytes, 13.90%
[00:00:00] [========================================]      13/13      0x0                                                                                           [00:00:00] [========================================]       1/1       0x8000                                                                                        [00:00:14] [========================================]     680/680     0x10000                                                                                       [2023-03-02T20:13:54Z INFO ] Flashing has completed!
jnross commented 1 year ago

I ran my test with the changes from https://github.com/esp-rs/espflash/pull/359. That does not appear to resolve this issue in my testing, like reverting 1c054e84127c08a3ccfa60ada39a6185ed1c9ee0 does.

➜  espflash git:(update-stubs) ✗ git log -1 --oneline
52cb766 (HEAD -> update-stubs, MabezDev/update-stubs) Disable RTC watchdog when not using the stub
➜  espflash git:(update-stubs) ✗ cargo run flash binary --port /dev/cu.usbmodem3212201
    Finished dev [unoptimized + debuginfo] target(s) in 0.09s
     Running `/Users/joe/src/espflash/target/debug/espflash flash binary --port /dev/cu.usbmodem3212201`
[2023-03-02T20:22:59Z INFO ] Serial port: '/dev/cu.usbmodem3212201'
[2023-03-02T20:22:59Z INFO ] Connecting...
[2023-03-02T20:23:00Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e2:4f:f8
App/part. size:    1,157,008/8,323,072 bytes, 13.90%
[00:00:00] [========================================]      13/13      0x0                                                                                           [00:00:00] [========================================]       1/1       0x8000                                                                                        Error: espflash::serial_error

  × Communication error while flashing device
  ├─▶ IO error while using serial port: Broken pipe
  ╰─▶ Broken pipe