search

esp-rs / esp-flasher-stub

Rust implementation of flasher stub located in esptool
Apache License 2.0
18 stars 10 forks source link

invalid stub handshake response received #63

Open sakuwa opened 5 months ago

sakuwa commented 5 months ago

Hello i got the following issue:

[2024-03-25T15:55:55Z INFO ] Serial port: 'COM5'
[2024-03-25T15:55:55Z INFO ] Connecting...
[2024-03-25T15:55:57Z INFO ] Using flash stub
Error:   x Error while connecting to device
  `-> Invalid stub handshake response received

i can connect with py -m esptool -p .... to my sparkfun esp32 thing board.

I use this instruction guide to flash the device: https://github.com/beeb/coffee-scale-app/blob/main/rs/README.md

Also i set the baudrate to a lower one (115200) in the espflash.toml without success.

I tried to find with google the issue with the handshake and thats why i set the baudrate to a lower part. What did i wrong or miss?

beeb commented 5 months ago

Can confirm, same issue here (windows, cargo-espflash 3.0.0). I didn't adjust the config from 2.x but I updated the target with espup if that's useful information.

Note that the board has a 26MHz crystal and CONFIG_XTAL_FREQ_26=y is set in the sdkconfig.

PS: happy to see a fellow user of my firmware here!

SergioGasquez commented 4 months ago

Hi! Mind trying to use the --no-stub flag?

Note that the board has a 26MHz crystal and CONFIG_XTAL_FREQ_26=y is set in the sdkconfig.

Correct, more information https://docs.esp-rs.org/book/troubleshooting/std.html#wrong-xtal-frequency

sakuwa commented 4 months ago

yeah after some more try and errors and short reading (stub is a kind of a bootloader?) right?

with this flag --no-stub is successfull but i was very confused.

@beeb yeah i am struggeling a litte bit but i after some breaks one step after another. But great project so far. :)

SergioGasquez commented 4 months ago

Could you try using this branch https://github.com/SergioGasquez/espflash/tree/feat/esp32-26mhz?

cargo install cargo-espflash --git https://github.com/SergioGasquez/espflash --branch feat/esp32-26mhz
sakuwa commented 4 months ago

i got a few timeout notification but it seems to work. No handshake error or need to set the --no-stub flag

SergioGasquez commented 4 months ago

i got a few timeout notification but it seems to work. No handshake error or need to set the --no-stub flag

Can you share the logs? Maybe there are still some missing tweaks

beeb commented 4 months ago

Hey @SergioGasquez thanks for looking into it. I can confirm that with the stable release and --no-stub the flashing works.

However this is what I get with your branch every time I try:

[2024-03-26T19:18:38Z INFO ] Serial port: 'COM3'
[2024-03-26T19:18:38Z INFO ] Connecting...
[2024-03-26T19:18:38Z INFO ] Using flash stub
Error: espflash::timeout

  × Error while connecting to device
  ╰─▶ Timeout while running command
sakuwa commented 4 months ago

@SergioGasquez I tried to make a log cargo espflash flash --release -L serial --monitor but i don´t find a file or something else. Sorry i´m a beginner in that case.

SergioGasquez commented 4 months ago

I tried to make a log cargo espflash flash --release -L serial --monitor

Logs are not enabled with the -L arguments. Logs are enabled by RUST_LOG=debug cargo espflash flash --release --monitor

However this is what I get with your branch every time I try.

Might share debug logs? Although I think I may know what's happening: The stubs are sending the sync message but espflash is not able to read it properly (different baudrate)

SergioGasquez commented 4 months ago

Just pushed a commit https://github.com/SergioGasquez/espflash/commit/d86a622250dee85bdf817fb7a86b300889033b78 to the branch, could you guys reinstall it and test it with logs enabled:

cargo install cargo-espflash --git https://github.com/SergioGasquez/espflash --branch feat/esp32-26mhz
RUST_LOG=debug cargo espflash flash --release --monitor
beeb commented 4 months ago

Thanks @SergioGasquez , here are the logs from my side (I shortened the data sequences for brevity):

[2024-04-02T17:13:57Z DEBUG] Flash(
        FlashArgs {
            build_args: BuildArgs {
                bin: None,
                example: None,
                features: None,
                frozen: false,
                locked: false,
                package: None,
                release: true,
                target: None,
                target_dir: None,
                unstable: None,
                flash_config_args: FlashConfigArgs {
                    flash_freq: None,
                    flash_mode: None,
                    flash_size: None,
                },
            },
            connect_args: ConnectArgs {
                after: HardReset,
                baud: None,
                before: DefaultReset,
                chip: None,
                confirm_port: false,
                list_all_ports: false,
                no_stub: false,
                port: None,
            },
            flash_args: FlashArgs {
                bootloader: None,
                erase_parts: None,
                erase_data_parts: None,
                log_format: Serial,
                min_chip_rev: 0,
                monitor: true,
                monitor_baud: None,
                partition_table: None,
                target_app_partition: None,
                partition_table_offset: None,
                ram: false,
                no_verify: false,
                no_skip: false,
            },
        },
    )
[2024-04-02T17:13:57Z DEBUG] connecting to crates.io:443 at 13.224.103.50:443
[2024-04-02T17:13:57Z DEBUG] No cached session for DnsName("crates.io")
[2024-04-02T17:13:57Z DEBUG] Not resuming any session
[2024-04-02T17:13:57Z DEBUG] Using ciphersuite TLS13_AES_128_GCM_SHA256
[2024-04-02T17:13:57Z DEBUG] Not resuming
[2024-04-02T17:13:57Z DEBUG] TLS1.3 encrypted extensions: [ServerNameAck]
[2024-04-02T17:13:57Z DEBUG] ALPN protocol is None
[2024-04-02T17:13:57Z DEBUG] created stream: Stream(RustlsStream)
[2024-04-02T17:13:57Z DEBUG] sending request GET https://crates.io/api/v1/crates/cargo-espflash/versions
[2024-04-02T17:13:57Z DEBUG] writing prelude: GET /api/v1/crates/cargo-espflash/versions HTTP/1.1
    Host: crates.io
    User-Agent: ureq/2.9.6
    Accept: */*
    accept-encoding: gzip
[2024-04-02T17:13:57Z DEBUG] Chunked body in response
[2024-04-02T17:13:57Z DEBUG] response 200 to GET https://crates.io/api/v1/crates/cargo-espflash/versions
[2024-04-02T17:13:57Z DEBUG] dropping stream: Stream(RustlsStream)
[2024-04-02T17:13:57Z DEBUG] Config: Config {
        baudrate: None,
        bootloader: None,
        connection: Connection {
            serial: None,
        },
        partition_table: None,
        usb_device: [
            UsbDevice {
                vid: 1027,
                pid: 24597,
            },
        ],
        save_path: "C:\\Users\\valentin\\AppData\\Roaming\\esp\\espflash\\config\\espflash.toml",
    }
[2024-04-02T17:13:57Z INFO ] Serial port: 'COM3'
[2024-04-02T17:13:57Z INFO ] Connecting...
[2024-04-02T17:13:57Z DEBUG] Using Classic reset strategy with delay of 50ms
[2024-04-02T17:13:57Z DEBUG] Boot Mode: 0x3
[2024-04-02T17:13:57Z DEBUG] Download Mode: false
[2024-04-02T17:13:57Z DEBUG] Writing command: Sync
[2024-04-02T17:13:57Z DEBUG] Writing command: Sync
[2024-04-02T17:13:58Z DEBUG] Writing command: Sync
[2024-04-02T17:13:58Z DEBUG] Writing command: Sync
[2024-04-02T17:13:58Z DEBUG] Writing command: Sync
[2024-04-02T17:13:58Z DEBUG] Failed to reset, error Connection(
        WrongBootMode(
            "0x3",
        ),
    ), retrying
[2024-04-02T17:13:58Z DEBUG] Using Classic reset strategy with delay of 500ms
[2024-04-02T17:13:58Z DEBUG] Boot Mode: 0x3
[2024-04-02T17:13:58Z DEBUG] Download Mode: false
[2024-04-02T17:13:58Z DEBUG] Writing command: Sync
[2024-04-02T17:13:59Z DEBUG] Writing command: Sync
[2024-04-02T17:13:59Z DEBUG] Writing command: Sync
[2024-04-02T17:13:59Z DEBUG] Writing command: ReadReg { address: 1073745920 }
[2024-04-02T17:13:59Z INFO ] Using flash stub
[2024-04-02T17:13:59Z DEBUG] Loading flash stub for chip: Esp32
[2024-04-02T17:13:59Z DEBUG] Write 12356 byte stub text
[2024-04-02T17:13:59Z DEBUG] Writing command: MemBegin { size: 12356, blocks: 3, block_size: 6144, offset: 1074266112, supports_encryption: false }
[2024-04-02T17:13:59Z DEBUG] Writing command: MemData { data: [0, ... 129], pad_to: 4, pad_byte: 0, sequence: 0 }
[2024-04-02T17:13:59Z DEBUG] Writing command: MemData { data: [162, ... 0], pad_to: 4, pad_byte: 0, sequence: 1 }
[2024-04-02T17:14:00Z DEBUG] Writing command: MemData { data: [230, ... 0], pad_to: 4, pad_byte: 0, sequence: 2 }
[2024-04-02T17:14:00Z DEBUG] Write 744 byte stub data
[2024-04-02T17:14:00Z DEBUG] Writing command: MemBegin { size: 744, blocks: 1, block_size: 6144, offset: 1073414144, supports_encryption: false }
[2024-04-02T17:14:00Z DEBUG] Writing command: MemData { data: [86, ... 0], pad_to: 4, pad_byte: 0, sequence: 0 }
[2024-04-02T17:14:00Z DEBUG] Finish stub write
[2024-04-02T17:14:00Z DEBUG] Writing command: MemEnd { no_entry: false, entry: 1074274836 }
[2024-04-02T17:14:00Z DEBUG] Stub written!
Error: espflash::timeout

  × Error while connecting to device
  ╰─▶ Timeout while running command
SergioGasquez commented 4 months ago

Just to confirm, these logs were using the latest commit of my branch? Looks like it's retrying lots of times the sync command (probably because it's not able to read it due to the different baud rate).

Also, could you try using the --before no-reset argument?

beeb commented 4 months ago

Yes this is on commit d86a622250dee85bdf817fb7a86b300889033b78. Here's the result with the --before no-reset argument:

[2024-04-07T13:55:54Z DEBUG] Flash(
        FlashArgs {
            build_args: BuildArgs {
                bin: None,
                example: None,
                features: None,
                frozen: false,
                locked: false,
                package: None,
                release: true,
                target: None,
                target_dir: None,
                unstable: None,
                flash_config_args: FlashConfigArgs {
                    flash_freq: None,
                    flash_mode: None,
                    flash_size: None,
                },
            },
            connect_args: ConnectArgs {
                after: HardReset,
                baud: None,
                before: NoReset,
                chip: None,
                confirm_port: false,
                list_all_ports: false,
                no_stub: false,
                port: None,
            },
            flash_args: FlashArgs {
                bootloader: None,
                erase_parts: None,
                erase_data_parts: None,
                log_format: Serial,
                min_chip_rev: 0,
                monitor: true,
                monitor_baud: None,
                partition_table: None,
                target_app_partition: None,
                partition_table_offset: None,
                ram: false,
                no_verify: false,
                no_skip: false,
            },
        },
    )
[2024-04-07T13:55:54Z DEBUG] connecting to crates.io:443 at 13.224.103.50:443
[2024-04-07T13:55:54Z DEBUG] No cached session for DnsName("crates.io")
[2024-04-07T13:55:54Z DEBUG] Not resuming any session
[2024-04-07T13:55:54Z DEBUG] Using ciphersuite TLS13_AES_128_GCM_SHA256
[2024-04-07T13:55:54Z DEBUG] Not resuming
[2024-04-07T13:55:54Z DEBUG] TLS1.3 encrypted extensions: [ServerNameAck]
[2024-04-07T13:55:54Z DEBUG] ALPN protocol is None
[2024-04-07T13:55:54Z DEBUG] created stream: Stream(RustlsStream)
[2024-04-07T13:55:54Z DEBUG] sending request GET https://crates.io/api/v1/crates/cargo-espflash/versions
[2024-04-07T13:55:54Z DEBUG] writing prelude: GET /api/v1/crates/cargo-espflash/versions HTTP/1.1
    Host: crates.io
    User-Agent: ureq/2.9.6
    Accept: */*
    accept-encoding: gzip
[2024-04-07T13:55:54Z DEBUG] Chunked body in response
[2024-04-07T13:55:54Z DEBUG] response 200 to GET https://crates.io/api/v1/crates/cargo-espflash/versions
[2024-04-07T13:55:54Z DEBUG] dropping stream: Stream(RustlsStream)
[2024-04-07T13:55:54Z DEBUG] Config: Config {
        baudrate: None,
        bootloader: None,
        connection: Connection {
            serial: None,
        },
        partition_table: None,
        usb_device: [
            UsbDevice {
                vid: 1027,
                pid: 24597,
            },
        ],
        save_path: "C:\\Users\\valentin\\AppData\\Roaming\\esp\\espflash\\config\\espflash.toml",
    }
[2024-04-07T13:55:54Z WARN ] Pre-connection option 'NoReset' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-04-07T13:55:54Z INFO ] Serial port: 'COM3'
[2024-04-07T13:55:54Z INFO ] Connecting...
[2024-04-07T13:55:54Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:55Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:56Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:57Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Writing command: Sync
[2024-04-07T13:55:58Z DEBUG] Failed to reset, error Connection(
        ConnectionFailed,
    ), retrying
Error: espflash::connection_failed

  × Error while connecting to device
  ╰─▶ Failed to connect to the device
  help: Ensure that the device is connected and the reset and boot pins are not being held down
SergioGasquez commented 2 months ago

Hi! Could you try with the new espflash version? I guess this is a stub issue, so it probably should be transferred

beeb commented 2 months ago

Hey @SergioGasquez sorry for the late reply.

Still no luck with espflash 3.1.0. Getting a Error: espflash::timeout when I don't pass the --before no-reset option, and I get a Error: espflash::connection_failed when I pass the --before no-reset option.

EDIT: wait I have not updated cargo-espflash I think, let me check

beeb commented 2 months ago

Ok I updated cargo-espflash to 3.1.0 and the error is slightly different:

without option:

Error:   × Error while connecting to device
  ╰─▶ Invalid stub handshake response received

with --before no-reset:

Error: espflash::connection_failed

  × Error while connecting to device
  ╰─▶ Failed to connect to the device

--no-stub works fine.