SDIO fails to read block in debug build with high frequency

[skibon02]

During testing, I took example code sd.rs and launched it on my STM32F401RET Nucleo board. In debug mode it stuck on first read_block function call in debug mode, but works fine in release mode:

Release run with 24Mhz initialization, 4-bit bus

$ cargo run --release -- --no-location
    Finished release [optimized] target(s) in 0.01s
     Running `probe-rs run --chip STM32F401RETx target/thumbv7em-none-eabihf/release/stm32hal_test --no-location`
     Erasing sectors ✔ [00:00:00] [###########################################################################################################################################] 32.00 KiB/32.00 KiB @ 35.71 KiB/s (eta 0s )
 Programming pages   ✔ [00:00:00] [###########################################################################################################################################] 29.00 KiB/29.00 KiB @ 29.64 KiB/s (eta 0s )    Finished in 1.894s
INFO  Clock setup successful!
INFO  Clocks result: "Clocks { hclk: Rate { raw: 42000000 }, pclk1: Rate { raw: 42000000 }, pclk2: Rate { raw: 42000000 }, timclk1: Rate { raw: 42000000 }, timclk2: Rate { raw: 42000000 }, sysclk: Rate { raw: 42000000 }, pll48clk: Some(Rate { raw: 48000000 }), i2s_clk: None }"
INFO  Clock setup successful 2!
INFO  Waiting for card...
INFO  SD Status: "SD Status { Bus Width: Four, Secured Mode: false, SD Memory Card Type: 0, Protected Area Size (B): 40, Speed Class: 3, Video Speed Class: 0, Application Performance Class: 0, Move Performance (MB/s): 3, AU Size: 9, Erase Size (units of AU): 8, Erase Timeout (s): 2, Discard Support: false }"
INFO  Card detected: nbr of blocks: 1929216
INFO  Read start...
INFO  Read finished! First 10 bytes:
12 
34 
56 
78 
90 
AB 
CD 
EF 
12 
34 
INFO  Write zeroes start...
INFO  Write zeroes finished!
INFO  Read start...
INFO  Read finished! First 10 bytes:
0 
0 
0 
0 
0 
0 
0 
0 
0 
0 
INFO  Write random data start...
INFO  Write random data finished!

Debug run with 24Mhz initialization, 4-bit bus

$ cargo run -- --no-location
    Finished dev [unoptimized + debuginfo] target(s) in 0.01s
     Running `probe-rs run --chip STM32F401RETx target/thumbv7em-none-eabihf/debug/stm32hal_test --no-location`
     Erasing sectors ✔ [00:00:02] [#########################################################################################################################################] 128.00 KiB/128.00 KiB @ 44.01 KiB/s (eta 0s )
 Programming pages   ✔ [00:00:02] [###########################################################################################################################################] 82.00 KiB/82.00 KiB @ 30.84 KiB/s (eta 0s )    Finished in 5.586s
INFO  Clock setup successful!
INFO  Clock setup successful 2!
INFO  Waiting for card...
INFO  SD Status: "SD Status { Bus Width: Four, Secured Mode: false, SD Memory Card Type: 0, Protected Area Size (B): 40, Speed Class: 3, Video Speed Class: 0, Application Performance Class: 0, Move Performance (MB/s): 3, AU Size: 9, Erase Size (units of AU): 8, Erase Timeout (s): 2, Discard Support: false }"
INFO  Card detected: nbr of blocks: 1929216
INFO  Read start...

Moreover, lowering initialization frequency or bus width may help:

Debug run with 1Mhz initialization, 4-bit bus

$ cargo run -- --no-location
   Compiling stm32hal_test v0.1.0 (/home/skygrel19/projects/stm32hal_test)
    Finished dev [unoptimized + debuginfo] target(s) in 0.13s
     Running `probe-rs run --chip STM32F401RETx target/thumbv7em-none-eabihf/debug/stm32hal_test --no-location`
     Erasing sectors ✔ [00:00:02] [#########################################################################################################################################] 128.00 KiB/128.00 KiB @ 43.90 KiB/s (eta 0s )
 Programming pages   ✔ [00:00:02] [###########################################################################################################################################] 82.00 KiB/82.00 KiB @ 31.07 KiB/s (eta 0s )    Finished in 5.574s
INFO  Clock setup successful!
INFO  Clocks result: "Clocks { hclk: Rate { raw: 42000000 }, pclk1: Rate { raw: 42000000 }, pclk2: Rate { raw: 42000000 }, timclk1: Rate { raw: 42000000 }, timclk2: Rate { raw: 42000000 }, sysclk: Rate { raw: 42000000 }, pll48clk: Some(Rate { raw: 48000000 }), i2s_clk: None }"
INFO  Clock setup successful 2!
INFO  Waiting for card...
INFO  SD Status: "SD Status { Bus Width: Four, Secured Mode: false, SD Memory Card Type: 0, Protected Area Size (B): 40, Speed Class: 3, Video Speed Class: 0, Application Performance Class: 0, Move Performance (MB/s): 3, AU Size: 9, Erase Size (units of AU): 8, Erase Timeout (s): 2, Discard Support: false }"
INFO  Card detected: nbr of blocks: 1929216
INFO  Read start...
INFO  Read finished! First 10 bytes:
12 
34 
56 
78 
90 
AB 
CD 
EF 
12 
34 
INFO  Write zeroes start...
ERROR Failed to write block: "TxUnderErr"
INFO  Write zeroes finished!
INFO  Read start...
ERROR Failed to read block: "Timeout"
INFO  Read finished! First 10 bytes:
12 
34 
56 
78 
90 
AB 
CD 
EF 
12 
34 
INFO  Write random data start...
ERROR Failed to write block: "Timeout"
INFO  Write random data finished!

Debug run with 1Mhz initialization, 1-bit bus

$ cargo run -- --no-location
   Compiling stm32hal_test v0.1.0 (/home/skygrel19/projects/stm32hal_test)
    Finished dev [unoptimized + debuginfo] target(s) in 0.14s
     Running `probe-rs run --chip STM32F401RETx target/thumbv7em-none-eabihf/debug/stm32hal_test --no-location`
     Erasing sectors ✔ [00:00:02] [#########################################################################################################################################] 128.00 KiB/128.00 KiB @ 44.08 KiB/s (eta 0s )
 Programming pages   ✔ [00:00:02] [###########################################################################################################################################] 78.00 KiB/78.00 KiB @ 30.96 KiB/s (eta 0s )    Finished in 5.442s
INFO  Clock setup successful!
INFO  Clocks result: "Clocks { hclk: Rate { raw: 42000000 }, pclk1: Rate { raw: 42000000 }, pclk2: Rate { raw: 42000000 }, timclk1: Rate { raw: 42000000 }, timclk2: Rate { raw: 42000000 }, sysclk: Rate { raw: 42000000 }, pll48clk: Some(Rate { raw: 48000000 }), i2s_clk: None }"
INFO  Clock setup successful 2!
INFO  Waiting for card...
INFO  SD Status: "SD Status { Bus Width: One, Secured Mode: false, SD Memory Card Type: 0, Protected Area Size (B): 40, Speed Class: 3, Video Speed Class: 0, Application Performance Class: 0, Move Performance (MB/s): 3, AU Size: 9, Erase Size (units of AU): 8, Erase Timeout (s): 2, Discard Support: false }"
INFO  Card detected: nbr of blocks: 1929216
INFO  Read start...
INFO  Read finished! First 10 bytes:
12 
34 
56 
78 
90 
AB 
CD 
EF 
12 
34 
INFO  Write zeroes start...
INFO  Write zeroes finished!
INFO  Read start...
INFO  Read finished! First 10 bytes:
0 
0 
0 
0 
0 
0 
0 
0 
0 
0 
INFO  Write random data start...
INFO  Write random data finished!

Here's the code:
https://github.com/skibon02/stm32hal-sdio-issue

Behaviour is the same, no matter what sd card is used (tested on several SDSC and SDHC cards)

[burrbull]

By default Rust optimizes code bad enough in debug mode. Although usually it is not needed.

You can partially workaround this by specifying dependency crates you want optimize using cargo profiles.
For example optimize all except user code. Or user code + HAL.
See https://doc.rust-lang.org/cargo/reference/profiles.html#overrides

[skibon02]

Yeah, I know how much better code performs in release mode in terms of both execution time and memory usage. However, this also makes debugging more difficult, as some lines may be skipped during debugging. Mostly, embedded peripherals are designed to work well even when the code is executing slower, but to address this, it may be necessary to recheck the implementation across different layers of abstraction, or to make use of DMA.