Skip to content
This repository has been archived by the owner on May 27, 2024. It is now read-only.

Demo code hangs at write on ESP32 #31

Closed
kovmarci86 opened this issue Nov 11, 2023 · 21 comments · Fixed by #33
Closed

Demo code hangs at write on ESP32 #31

kovmarci86 opened this issue Nov 11, 2023 · 21 comments · Fixed by #33

Comments

@kovmarci86
Copy link

Hi,
I'm using a Lilygo Lora32 T3 1.6.1 board with an ESP32 chip. I'm not sure what I'm doing wrong, but the write operations block forever.
The command I used to start the demo: cargo +esp run --release --example demo --features esp32 --target xtensa-esp32-none-elf

I tried with new esp-hal versions, with a pull request to disable the other core, and I originally reproduced this while using embassy.

The output:

Chip type:         esp32 (revision v1.1)
Crystal frequency: 40MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Embedded Flash, Coding Scheme None
MAC address:       64:b7:08:ad:1d:54
App/part. size:    92,336/4,128,768 bytes, 2.24%
[00:00:01] [========================================]      17/17      0x1000
[00:00:00] [========================================]       1/1       0x8000
[00:00:02] [========================================]      27/27      0x10000
[2023-11-11T17:55:59Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 188777542, 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
0x3fff0030 - _stack_end_cpu0
    at ??:??
load:0x40078000,len:15576
0x40078000 - ets_delay_us
    at ??:??
load:0x40080400,len:4
0x40080400 - _init_end
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _init_end
    at ??:??
entry 0x4008064c
0x4008064c - __user_exception
    at ??:??
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 (34) boot: Multicore bootloader
I (38) boot: chip revision: v1.1
I (42) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (51) boot.esp32: SPI Flash Size : 4MB
I (55) boot: Enabling RNG early entropy source...
I (61) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (72) 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=0292ch ( 10540) map
I (110) esp_image: segment 1: paddr=00012954 vaddr=40080000 size=022bch (  8892) load
I (119) esp_image: segment 2: paddr=00014c18 vaddr=00000000 size=0b400h ( 46080)
I (140) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=06864h ( 26724) map
I (151) boot: Loaded app from partition at offset 0x10000
I (151) boot: Disabling RNG early entropy source...
Flash size = 4194304
Read from 129000:  [70, a7, 20, 25, ec, d3, 16, 3a, 01, 42, 26, 00, 5a, 54, 72, 45, 18, c0, 20, 00, c0, 20, 00, 06, e9, ff, 00, 00, 00, 00, 17, 40]
@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 13, 2023

The address it is reading from / writing to looks a bit weird in your logs: Read from 129000 - it should use the NVM partition (the demo hardcodes the address to 0x9000

@Natureshadow
Copy link

I can confirm that the write method hangs, even when writing to my own partition. I guess the bytes.is_empty() condition never becomes true for some reason.

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

On what chip exactly? (including revision) For all chips except ESP32 we just call the ROM functions, On ESP32 unfortunately we have to do a bit more (but not that much more)

@Natureshadow
Copy link

On what chip exactly? (including revision) For all chips except ESP32 we just call the ROM functions, On ESP32 unfortunately we have to do a bit more (but not that much more)

nik@frifot ~/S/s/hazelos (main)> cargo espflash board-info
[2023-11-15T10:43:03Z INFO ] Serial port: '/dev/ttyUSB0'
[2023-11-15T10:43:03Z INFO ] Connecting...
[2023-11-15T10:43:04Z INFO ] Using flash stub
Chip type:         esp32 (revision v1.0)
Crystal frequency: 40MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
MAC address:       c8:c9:a3:c9:a7:ac

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

Thanks - looks like the same I have here:

❯ cargo +esp run --release --example demo --features esp32 --target xtensa-esp32-none-elf
    Finished release [optimized] target(s) in 1.46s
     Running `espflash flash --monitor target\xtensa-esp32-none-elf\release\examples\demo`
[2023-11-15T10:50:57Z INFO ] Serial port: 'COM4'
[2023-11-15T10:50:57Z INFO ] Connecting...
[2023-11-15T10:50:57Z INFO ] Using flash stub
[2023-11-15T10:50:57Z WARN ] Setting baud rate higher than 115,200 can cause issues
Chip type:         esp32 (revision v1.0)
Crystal frequency: 40MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       cc:50:e3:99:49:e8
App/part. size:    92,400/4,128,768 bytes, 2.24%
[00:00:00] [========================================]      17/17      0x1000
[00:00:00] [========================================]       1/1       0x8000
[00:00:00] [========================================]      26/26      0x10000
[2023-11-15T10:50:59Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

��������������������Ҫ�j

rst:0x1 (POWERON_RESET),boot:0x13 (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
0x3fff0030 - _stack_end_cpu0
    at ??:??
load:0x40078000,len:15576
0x40078000 - ets_delay_us
    at ??:??
load:0x40080400,len:4
0x40080400 - _init_end
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _init_end
    at ??:??
entry 0x4008064c
0x4008064c - __user_exception
    at ??:??
I (30) 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: v1.0
I (41) boot.esp32: SPI Speed      : 40MHz
I (45) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (54) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (63) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 003f0000
I (93) boot: End of partition table
I (97) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=0292ch ( 10540) map
I (110) esp_image: segment 1: paddr=00012954 vaddr=40080000 size=01fa8h (  8104) load
I (118) esp_image: segment 2: paddr=00014904 vaddr=00000000 size=0b714h ( 46868)
I (139) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=068a0h ( 26784) map
I (150) boot: Loaded app from partition at offset 0x10000
I (150) boot: Disabling RNG early entropy source...
Flash size = 4194304
Read from 9000:  [14, 29, 3e, 53, 14, 29, 3e, 53, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff]
Written to 9000: [15, 2b, 41, 57, 15, 2b, 41, 57, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff]
Read from 9000:  [15, 2b, 41, 57, 15, 2b, 41, 57, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff]

@Natureshadow
Copy link

I have copied the example code into my own project created with cargo generate esp-rs/esp-template because inside the esp-storage repository, cargo fails to find the xtensa-esp32-non-elf target for some reason.

Maybe you can help me to run the example in the same way as you do?

I get:

> cargo +esp run --release --example demo --features esp32 --target xtensa-esp32-none-elf
    Finished release [optimized] target(s) in 0.08s
     Running `espflash flash --monitor target/xtensa-esp32-none-elf/release/examples/demo`
error: could not execute process `espflash flash --monitor target/xtensa-esp32-none-elf/release/examples/demo` (never executed)

Caused by:
  No such file or directory (os error 2)
> cargo espflash flash --release --example demo --features esp32 --target xtensa-esp32-none-elf
[2023-11-15T11:15:05Z INFO ] Serial port: '/dev/ttyUSB0'
[2023-11-15T11:15:05Z INFO ] Connecting...
[2023-11-15T11:15:05Z INFO ] Using flash stub
error: failed to run `rustc` to learn about target-specific information

Caused by:
  process didn't exit successfully: `/home/nik/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/rustc - --crate-name ___ --print=file-names -C link-arg=-Tlinkall.x --target xtensa-esp32-none-elf --crate-type bin --crate-type rlib --crate-type dylib --crate-type cdylib --crate-type staticlib --crate-type proc-macro --print=sysroot --print=split-debuginfo --print=crate-name --print=cfg` (exit status: 1)
  --- stderr
  error: Error loading target specification: Could not find specification for target "xtensa-esp32-none-elf". Run `rustc --print target-list` for a list of built-in targets

@Natureshadow
Copy link

Natureshadow commented Nov 15, 2023

Oh, thinking about it… I had to change the demo code at one point, because this doesn't work:

        #[cfg(feature = "esp32")]
        let system = peripherals.DPORT.split();

esp32_hal does not have a DPORT peripheral. I used the SYSTEM peripheral instead. Maybe something changed in esp32_hal here as well?

In general, could you explain the relevance of the timer setup code as used in the demo for the Flash access? I don't understand why I need to get a timer group and one time from it, but the timer is never used later on.

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

Ah maybe you don't have espflash installed? (You have cargo-espflash, see https://crates.io/crates/espflash)

With espflash installed the first command should just work

Or you can try
cargo +esp espflash flash --release --example demo --features esp32 --target xtensa-esp32-none-elf
to run it with the esp-toolchain

In a generated project you don't need +esp since the template creates rust-toolchain.toml for you

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

The demo uses an older version of ESP-HAL and we renamed DPORT to SYSTEM in our latest release

The whole timer thing in the demo is also because of the older HAL version: now we deactivate the watchdog-timer in HAL before running user-code. Before the user had to deactivate the WDT manually

.... and now I'm wondering if anything changed in esp-hal which breaks esp-storage 🤔

So would be great if you could check if it's working in the repository without any changes

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

Ok doesn't seem like there is anything changed in esp-hal causing any problems here

@Natureshadow
Copy link

The example run from a fresh clone of the repository also hangs, both with espflash and cargo-espflash.

@Natureshadow
Copy link

Surprisingly, the first read already returns only 0xff bytes:

Flash size = 4194304
Read from 9000:  [ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff]

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

All 0xff is fine since probably nothing was ever written to that flash page.

Could you post the full output (including messages from the 2nd stage bootloader and the ROM)?

@Natureshadow
Copy link

nik@frifot /t/esp-storage (main)> cargo +esp run --release --example demo --features esp32 --target xtensa-esp32-none-elf
    Finished release [optimized] target(s) in 0.03s
     Running `espflash flash --monitor target/xtensa-esp32-none-elf/release/examples/demo`
[2023-11-15T12:37:38Z INFO ] Serial port: '/dev/ttyUSB0'
[2023-11-15T12:37:38Z INFO ] Connecting...
[2023-11-15T12:37:38Z INFO ] Using flash stub
Chip type:         esp32 (revision v1.0)
Crystal frequency: 40MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
MAC address:       c8:c9:a3:c9:a7:ac
App/part. size:    92,384/4,128,768 bytes, 2.24%
[00:00:01] [========================================]      17/17      0x1000                                                      [00:00:00] [========================================]       1/1       0x8000                                                      [00:00:02] [========================================]      26/26      0x10000                                                     [2023-11-15T12:37:43Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (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
0x3fff0030 - _stack_end_cpu0
    at ??:??
load:0x40078000,len:15576
0x40078000 - ets_delay_us
    at ??:??
load:0x40080400,len:4
0x40080400 - _init_end
    at ??:??
ho 8 tail 4 room 4
load:0x40080404,len:3876
0x40080404 - _init_end
    at ??:??
entry 0x4008064c
0x4008064c - __user_exception
    at ??:??
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: v1.0
I (41) 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 (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 003f0000
I (93) boot: End of partition table
I (97) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=028e0h ( 10464) map
I (110) esp_image: segment 1: paddr=00012908 vaddr=40080000 size=01fa8h (  8104) load
I (118) esp_image: segment 2: paddr=000148b8 vaddr=00000000 size=0b760h ( 46944) 
I (139) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=06898h ( 26776) map
I (150) boot: Loaded app from partition at offset 0x10000
I (150) boot: Disabling RNG early entropy source...
Flash size = 4194304
Read from 9000:  [ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff, ff]

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 15, 2023

Good news .... I finally found a board showing that behavior. Bad news: it's a revision 3 (so if I can fix it we don't know if it fixes your problems) and I currently wonder why that is happening only on that board

@Natureshadow
Copy link

If it helps, I can give you access to an environment with the board using tmate (SSH).

@Natureshadow
Copy link

I traced it to cache_read_disable_rom(0) in

cache_read_disable_rom(cpu_num)
never returning.

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 16, 2023

@Natureshadow
Copy link

@Natureshadow could you try the branch https://github.com/esp-rs/esp-storage/tree/fix-some-esp32 ?

Done. Works ☺!

@bjoernQ
Copy link
Contributor

bjoernQ commented Nov 16, 2023

Thanks! Will do some cleanup and then this is hopefully solved

@bjoernQ bjoernQ mentioned this issue Nov 16, 2023
@github-project-automation github-project-automation bot moved this from Todo to Done in esp-rs Nov 16, 2023
@kovmarci86
Copy link
Author

Hi, I can also confirm it works now. Thank you!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants