esp-idf
esp-idf copied to clipboard
espressif
SDSPI Example not working properly (IDFGH-11213)
Answers checklist.
- [X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
- [X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
- [X] I have searched the issue tracker for a similar issue and not found a similar issue.
General issue report
IDF Version
ESP-IDF v5.1.1-dirty
Operating System used
Docker Container under Windows
Project Build Type
Command Line -> Bash
Development Kit
Custom PCB
Power Supply used
Stepped down from 230V Mains via on board Transformers
Expected Behavior
Mounting the SD Card and writing to it
Actual Behavior
Upon running the example the following ouput occurs:
I (0) cpu_start: App cpu up.
I (228) cpu_start: Pro cpu start user code
I (228) cpu_start: cpu freq: 160000000 Hz
I (228) cpu_start: Application information:
I (231) cpu_start: Project name: sd_card
I (236) cpu_start: App version: v5.1.1-dirty
I (242) cpu_start: Compile time: Oct 10 2023 13:05:25
I (248) cpu_start: ELF file SHA256: 59cd348f36d9b4f3...
I (254) cpu_start: ESP-IDF: v5.1.1-dirty
I (259) cpu_start: Min chip rev: v0.0
I (264) cpu_start: Max chip rev: v0.99
I (269) cpu_start: Chip rev: v0.1
I (273) heap_init: Initializing. RAM available for dynamic allocation:
I (281) heap_init: At 3FC96560 len 000531B0 (332 KiB): DRAM
I (287) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (293) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (300) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
W (306) spi_flash: Octal flash chip is using but dio mode is selected, will automatically swich to Octal mode
I (317) spi_flash: detected chip: mxic (opi)
I (321) spi_flash: flash io: opi_str
W (326) spi_flash: Detected size(32768k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (339) sleep: Configure to isolate all GPIO pins in sleep state
I (346) sleep: Enable automatic switching of GPIO sleep configuration
I (353) app_start: Starting scheduler on CPU0
I (358) app_start: Starting scheduler on CPU1
I (358) main_task: Started on CPU0
I (368) main_task: Calling app_main()
I (368) example: Initializing SD card
I (378) example: Using SPI peripheral
I (378) example: Mounting filesystem
I (388) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (438) sdspi_transaction: cmd=52, R1 response: command not supported
I (478) sdspi_transaction: cmd=5, R1 response: command not supported
Afterwards it hangs without any further info.
This behavior is observed when running various SD Cards, all of the same capacity (32GB, as that is all we have)
This issue does not occur with the example whilst running idf version 4.4.
This README.md states that 10k PullUp is required for GPIO15 (MOSI). There were leaders that worked without PullUp resistance, and leaders that did not work without PullUp resistance.
https://github.com/espressif/esp-idf/tree/master/examples/storage/sd_card/sdspi
If that is the case, why would it work with IDF Version 4.4?
It is the same hardware.
But we can investigate that.
So, we added in PullUps for all traces (MISO, MOSI, SCLK, CS)
Behavior in idf version 4.4 stayed functional, with occasionally occurring timeouts. Behavior in idf version 5.1 had no change, the behavior is identical to the behavior originally described,
Behavior in idf version 4.4 stayed functional, with occasionally occurring timeouts.
MOSI only PullUp is required.
We have a PullUp on the MOSI and according to the Documentation it is supposed to be on all pins.
However, after some further attempts, and removing the only other device on that SPI Bus, we were able to get a different Error under idf version 5.1, which is at least somewhat encouraging.
I (378) example: Mounting filesystem
I (388) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (398) sdspi_transaction: cmd=52, R1 response: command CRC error
E (398) sdmmc_io: sdmmc_io_reset: unexpected return: 0x109
E (408) vfs_fat_sdmmc: sdmmc_card_init failed (0x109).
I (408) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
E (418) example: Failed to initialize the card (ESP_ERR_INVALID_CRC). Make sure SD card lines have pull-up resistors in place.
I (438) main_task: Returned from app_main()
We removed all the Pull Ups Except for the MOSI, the behavior did not change aside from totally removing the CRC failure and returning completely to the original behavior.
We decided to use a logic analyzer to see if the signals might be problematic and these are the results:
All of this is followed by 20 instances of this:
And ending on these:
We are confused by the seemingly unneeded, and uncommanded, clocking (seen on the D0 line) without the CS being active (D1 line) but with Activity on the MISO line (D2)...
my environment:
$ idf.py --version
ESP-IDF v5.1.1-229-ga9aea676e7-dirty
I used this. https://github.com/espressif/esp-idf/tree/master/examples/storage/sd_card/sdspi
This is my log. CS connect to GPIO34.
I (0) cpu_start: App cpu up.
I (206) cpu_start: Pro cpu start user code
I (206) cpu_start: cpu freq: 160000000 Hz
I (206) cpu_start: Application information:
I (209) cpu_start: Project name: sd_card
I (214) cpu_start: App version: v5.1.1-229-ga9aea676e7-dirty
I (221) cpu_start: Compile time: Oct 27 2023 09:25:26
I (227) cpu_start: ELF file SHA256: fc207b6ee82e6d32...
I (233) cpu_start: ESP-IDF: v5.1.1-229-ga9aea676e7-dirty
I (240) cpu_start: Min chip rev: v0.0
I (244) cpu_start: Max chip rev: v0.99
I (249) cpu_start: Chip rev: v0.1
I (254) heap_init: Initializing. RAM available for dynamic allocation:
I (261) heap_init: At 3FC96540 len 000531D0 (332 KiB): DRAM
I (267) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (274) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (280) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
I (287) spi_flash: detected chip: gd
I (291) spi_flash: flash io: dio
W (295) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (308) sleep: Configure to isolate all GPIO pins in sleep state
I (315) sleep: Enable automatic switching of GPIO sleep configuration
I (322) app_start: Starting scheduler on CPU0
I (327) app_start: Starting scheduler on CPU1
I (327) main_task: Started on CPU0
I (337) main_task: Calling app_main()
I (337) example: Initializing SD card
I (347) example: Using SPI peripheral
I (347) example: Mounting filesystem
I (357) gpio: GPIO[34]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (367) sdspi_transaction: cmd=52, R1 response: command not supported
I (417) sdspi_transaction: cmd=5, R1 response: command not supported
I (457) example: Filesystem mounted
Name: SL32G
Type: SDHC/SDXC
Speed: 20.00 MHz (limit: 20.00 MHz)
Size: 30436MB
CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9
SSR: bus_width=1
E (398) sdmmc_io: sdmmc_io_reset: unexpected return: 0x109
This error has been reported several times in the past. This error can be resolved by either:
- The connection is incorrect.
- The connection cable is too long.
- There is no pull-up resistor on MOSI.
- The speed is too high. Try changing it (lower). //host.max_freq_khz = 10000;
- Replace the SD card with one that supports high speed.
Alright so:
- We have proper Connection(it did work under IDF v4.4 after all)
- We have a fairly short path of about 9cm of traces
- We do have a 10kOhm PullUp on the MOSI
- Adjusting the Speed didn't help
- We tried the same SL32G type of SD Card as you did and it didn't work either
What we can confirm tho is this:
- It doesn't work at all with 32GB Adata Cards, both Premier Cards and the generic ones
- With the Adata Cards the originally described behavior stays.
- With the 10kOhm PullUp on the Mosi we can observe this behavior with SL32G:
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x28 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40048dfe
SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:1
load:0x3fce3818,len:0x16f4
0x40048dfe: uart_rx_readbuff in ROM
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (33) boot: ESP-IDF v5.1.1-dirty 2nd stage bootloader
I (33) boot: compile time Oct 10 2023 13:05:33
I (34) boot: Multicore bootloader
I (37) boot: chip revision: v0.1
I (41) boot.esp32s3: Boot SPI Speed : 80MHz
I (45) boot.esp32s3: SPI Mode : SLOW READ
I (51) boot.esp32s3: SPI Flash Size : 2MB
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 (87) boot: 2 factory factory app 00 00 00010000 00100000
I (94) boot: End of partition table
I (98) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=0e820h ( 59424) map
I (121) esp_image: segment 1: paddr=0001e848 vaddr=3fc93300 size=017d0h ( 6096) load
I (123) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=2b768h (178024) map
I (169) esp_image: segment 3: paddr=0004b790 vaddr=3fc94ad0 size=011ach ( 4524) load
I (171) esp_image: segment 4: paddr=0004c944 vaddr=40374000 size=0f258h ( 62040) load
I (198) boot: Loaded app from partition at offset 0x10000
I (199) boot: Disabling RNG early entropy source...
I (210) cpu_start: Multicore app
I (210) cpu_start: Pro cpu up.
I (210) cpu_start: Starting app cpu, entry point is 0x40375370
0x40375370: call_start_cpu1 at /opt/esp/idf/components/esp_system/port/cpu_start.c:154
I (0) cpu_start: App cpu up.
I (228) cpu_start: Pro cpu start user code
I (228) cpu_start: cpu freq: 160000000 Hz
I (228) cpu_start: Application information:
I (231) cpu_start: Project name: sd_card
I (236) cpu_start: App version: v5.1.1-dirty
I (241) cpu_start: Compile time: Oct 10 2023 13:05:25
I (248) cpu_start: ELF file SHA256: 708add7741626192...
I (254) cpu_start: ESP-IDF: v5.1.1-dirty
I (259) cpu_start: Min chip rev: v0.0
I (264) cpu_start: Max chip rev: v0.99
I (268) cpu_start: Chip rev: v0.1
I (273) heap_init: Initializing. RAM available for dynamic allocation:
I (280) heap_init: At 3FC96560 len 000531B0 (332 KiB): DRAM
I (287) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (293) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (299) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
W (306) spi_flash: Octal flash chip is using but dio mode is selected, will automatically swich to Octal mode
I (316) spi_flash: detected chip: mxic (opi)
I (321) spi_flash: flash io: opi_str
W (326) spi_flash: Detected size(32768k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (339) sleep: Configure to isolate all GPIO pins in sleep state
I (346) sleep: Enable automatic switching of GPIO sleep configuration
I (353) app_start: Starting scheduler on CPU0
I (358) app_start: Starting scheduler on CPU1
I (358) main_task: Started on CPU0
I (368) main_task: Calling app_main()
I (368) example: Initializing SD card
I (378) example: Using SPI peripheral
I (378) example: Mounting filesystem
I (388) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (438) sdspi_transaction: cmd=5, R1 response: command not supported
E (1438) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107
E (1438) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).
I (1438) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
E (1448) example: Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place.
I (1458) main_task: Returned from app_main()
- We can observe this reproducably
- We know the Power Supply is stable
- TVS Diodes(D20) is 5V(No measurable signal distortion)
- The only difference between the schematic and the real world board is the 10kOhm resistor on CMD and DAT0 through 3, as described in the IDF Documentation
This is the only difference I can tell.
I (233) cpu_start: ESP-IDF: v5.1.1-229-ga9aea676e7-dirty
I (254) cpu_start: ESP-IDF: v5.1.1-dirty
I (357) gpio: GPIO[34]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (388) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
We are genuinely stumped.
The error persists throughout all the versions of 5.X we tested:
- v5.1-564-g8d2dbd461f-dirty
- v5.1.1-dirty
- v5.2-dev-2317-g3247253671-dirty (Pulled from the master branch, not supposed to do that but curiosity and all)
We can't seem to track down v5.1.1-229-ga9aea676e7-dirty but honestly, we aren't willing to invest significantly more time into trying to find a version of v5.1.1 that works, when the error could still well be hardware related....
Although it may not apply to this case, there have been cases in the past where the GPIO mark on the ESP32 board was different from the actual one.
I connected all GPIOs and LEDs and changed them to the correct markings.
I doubt that is the case here at all as we run our own custom board with an ESP32-S3-WROOM-2 Module.
Alright so, we decided to dig deep into the sdmmc lib and traced the ESP_ERR_TIMEOUT occuring into the sdmmc_send_cmd_send_op_cond Function in the sdmmc_cmd.c file. This is likely intended behavior, however we would like to understand this a bit better, therefore we added in a bunch of Log Statemens:
esp_err_t sdmmc_send_cmd_send_op_cond(sdmmc_card_t* card, uint32_t ocr, uint32_t *ocrp)
{
esp_err_t err;
/* If the host supports this, keep card clock enabled
* from the start of ACMD41 until the card is idle.
* (Ref. SD spec, section 4.4 "Clock control".)
*/
if (card->host.set_cclk_always_on != NULL) {
ESP_LOGE(TAG, "host.set_cclk_always_on != NULL");
err = card->host.set_cclk_always_on(card->host.slot, true);
if (err != ESP_OK) {
ESP_LOGE(TAG, "%s: set_cclk_always_on (1) err=0x%x", __func__, err);
return err;
}
ESP_LOGV(TAG, "%s: keeping clock on during ACMD41", __func__);
}
sdmmc_command_t cmd = {
.arg = ocr,
.flags = SCF_CMD_BCR | SCF_RSP_R3,
.opcode = SD_APP_OP_COND
};
int nretries = SDMMC_SEND_OP_COND_MAX_RETRIES;
int err_cnt = SDMMC_SEND_OP_COND_MAX_ERRORS;
for (; nretries != 0; --nretries) {
ESP_LOGE(TAG, "Retry Num : %i", nretries);
bzero(&cmd, sizeof cmd);
cmd.arg = ocr;
cmd.flags = SCF_CMD_BCR | SCF_RSP_R3;
if (!card->is_mmc) { /* SD mode */
ESP_LOGE(TAG, "Card is SD");
cmd.opcode = SD_APP_OP_COND;
err = sdmmc_send_app_cmd(card, &cmd);
} else { /* MMC mode */
cmd.arg &= ~MMC_OCR_ACCESS_MODE_MASK;
cmd.arg |= MMC_OCR_SECTOR_MODE;
cmd.opcode = MMC_SEND_OP_COND;
err = sdmmc_send_cmd(card, &cmd);
}
if (err != ESP_OK) {
if (--err_cnt == 0) {
ESP_LOGE(TAG, "%s: sdmmc_send_app_cmd err=0x%x", __func__, err);
goto done;
} else {
ESP_LOGE(TAG, "%s: ignoring err=0x%x", __func__, err);
continue;
}
}
// In SD protocol, card sets MEM_READY bit in OCR when it is ready.
// In SPI protocol, card clears IDLE_STATE bit in R1 response.
if (!host_is_spi(card)) {
if ((MMC_R3(cmd.response) & MMC_OCR_MEM_READY) ||
ocr == 0) {
break;
}
} else {
if ((SD_SPI_R1(cmd.response) & SD_SPI_R1_IDLE_STATE) == 0) {
break;
}
}
vTaskDelay(10 / portTICK_PERIOD_MS);
}
ESP_LOGE(TAG, "After Retries, Error : 0x%X", err);
if (nretries == 0) {
ESP_LOGE(TAG, "ESP_ERR_TIMOUT in %s", __func__ );
err = ESP_ERR_TIMEOUT;
goto done;
}
if (ocrp) {
*ocrp = MMC_R3(cmd.response);
}
err = ESP_OK;
done:
if (card->host.set_cclk_always_on != NULL) {
esp_err_t err_cclk_dis = card->host.set_cclk_always_on(card->host.slot, false);
if (err_cclk_dis != ESP_OK) {
ESP_LOGE(TAG, "%s: set_cclk_always_on (2) err=0x%x", __func__, err);
/* If we failed to disable clock, don't overwrite 'err' to return the original error */
}
ESP_LOGV(TAG, "%s: clock always-on mode disabled", __func__);
}
return err;
}
And this is the resulting output:
I (362) app_start: Starting scheduler on CPU1
I (362) main_task: Started on CPU0
I (372) main_task: Calling app_main()
I (372) example: Initializing SD card
I (382) example: Using SPI peripheral
I (382) example: Mounting filesystem
I (392) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (402) sdspi_transaction: cmd=52, R1 response: command not supported
I (442) sdspi_transaction: cmd=5, R1 response: command not supported
E (442) sdmmc_cmd: Retry Num : 100
E (442) sdmmc_cmd: Card is SD
E (452) sdmmc_cmd: Retry Num : 99
E (452) sdmmc_cmd: Card is SD
E (462) sdmmc_cmd: Retry Num : 98
E (462) sdmmc_cmd: Card is SD
E (472) sdmmc_cmd: Retry Num : 97
E (472) sdmmc_cmd: Card is SD
E (482) sdmmc_cmd: Retry Num : 96
E (482) sdmmc_cmd: Card is SD
E (492) sdmmc_cmd: Retry Num : 95
E (492) sdmmc_cmd: Card is SD
E (502) sdmmc_cmd: Retry Num : 94
E (502) sdmmc_cmd: Card is SD
E (512) sdmmc_cmd: Retry Num : 93
E (512) sdmmc_cmd: Card is SD
E (522) sdmmc_cmd: Retry Num : 92
E (522) sdmmc_cmd: Card is SD
E (532) sdmmc_cmd: Retry Num : 91
E (532) sdmmc_cmd: Card is SD
E (542) sdmmc_cmd: Retry Num : 90
E (542) sdmmc_cmd: Card is SD
E (552) sdmmc_cmd: Retry Num : 89
E (552) sdmmc_cmd: Card is SD
E (562) sdmmc_cmd: Retry Num : 88
E (562) sdmmc_cmd: Card is SD
E (572) sdmmc_cmd: Retry Num : 87
E (572) sdmmc_cmd: Card is SD
E (582) sdmmc_cmd: Retry Num : 86
E (582) sdmmc_cmd: Card is SD
E (592) sdmmc_cmd: Retry Num : 85
E (592) sdmmc_cmd: Card is SD
E (602) sdmmc_cmd: Retry Num : 84
E (602) sdmmc_cmd: Card is SD
E (612) sdmmc_cmd: Retry Num : 83
E (612) sdmmc_cmd: Card is SD
E (622) sdmmc_cmd: Retry Num : 82
E (622) sdmmc_cmd: Card is SD
E (632) sdmmc_cmd: Retry Num : 81
E (632) sdmmc_cmd: Card is SD
E (642) sdmmc_cmd: Retry Num : 80
E (642) sdmmc_cmd: Card is SD
E (652) sdmmc_cmd: Retry Num : 79
E (652) sdmmc_cmd: Card is SD
E (662) sdmmc_cmd: Retry Num : 78
E (662) sdmmc_cmd: Card is SD
E (672) sdmmc_cmd: Retry Num : 77
E (672) sdmmc_cmd: Card is SD
E (682) sdmmc_cmd: Retry Num : 76
E (682) sdmmc_cmd: Card is SD
E (692) sdmmc_cmd: Retry Num : 75
E (692) sdmmc_cmd: Card is SD
E (702) sdmmc_cmd: Retry Num : 74
E (702) sdmmc_cmd: Card is SD
E (712) sdmmc_cmd: Retry Num : 73
E (712) sdmmc_cmd: Card is SD
E (722) sdmmc_cmd: Retry Num : 72
E (722) sdmmc_cmd: Card is SD
E (732) sdmmc_cmd: Retry Num : 71
E (732) sdmmc_cmd: Card is SD
E (742) sdmmc_cmd: Retry Num : 70
E (742) sdmmc_cmd: Card is SD
E (752) sdmmc_cmd: Retry Num : 69
E (752) sdmmc_cmd: Card is SD
E (762) sdmmc_cmd: Retry Num : 68
E (762) sdmmc_cmd: Card is SD
E (772) sdmmc_cmd: Retry Num : 67
E (772) sdmmc_cmd: Card is SD
E (782) sdmmc_cmd: Retry Num : 66
E (782) sdmmc_cmd: Card is SD
E (792) sdmmc_cmd: Retry Num : 65
E (792) sdmmc_cmd: Card is SD
E (802) sdmmc_cmd: Retry Num : 64
E (802) sdmmc_cmd: Card is SD
E (812) sdmmc_cmd: Retry Num : 63
E (812) sdmmc_cmd: Card is SD
E (822) sdmmc_cmd: Retry Num : 62
E (822) sdmmc_cmd: Card is SD
E (832) sdmmc_cmd: Retry Num : 61
E (832) sdmmc_cmd: Card is SD
E (842) sdmmc_cmd: Retry Num : 60
E (842) sdmmc_cmd: Card is SD
E (852) sdmmc_cmd: Retry Num : 59
E (852) sdmmc_cmd: Card is SD
E (862) sdmmc_cmd: Retry Num : 58
E (862) sdmmc_cmd: Card is SD
E (872) sdmmc_cmd: Retry Num : 57
E (872) sdmmc_cmd: Card is SD
E (882) sdmmc_cmd: Retry Num : 56
E (882) sdmmc_cmd: Card is SD
E (892) sdmmc_cmd: Retry Num : 55
E (892) sdmmc_cmd: Card is SD
E (902) sdmmc_cmd: Retry Num : 54
E (902) sdmmc_cmd: Card is SD
E (912) sdmmc_cmd: Retry Num : 53
E (912) sdmmc_cmd: Card is SD
E (922) sdmmc_cmd: Retry Num : 52
E (922) sdmmc_cmd: Card is SD
E (932) sdmmc_cmd: Retry Num : 51
E (932) sdmmc_cmd: Card is SD
E (942) sdmmc_cmd: Retry Num : 50
E (942) sdmmc_cmd: Card is SD
E (952) sdmmc_cmd: Retry Num : 49
E (952) sdmmc_cmd: Card is SD
E (962) sdmmc_cmd: Retry Num : 48
E (962) sdmmc_cmd: Card is SD
E (972) sdmmc_cmd: Retry Num : 47
E (972) sdmmc_cmd: Card is SD
E (982) sdmmc_cmd: Retry Num : 46
E (982) sdmmc_cmd: Card is SD
E (992) sdmmc_cmd: Retry Num : 45
E (992) sdmmc_cmd: Card is SD
E (1002) sdmmc_cmd: Retry Num : 44
E (1002) sdmmc_cmd: Card is SD
E (1012) sdmmc_cmd: Retry Num : 43
E (1012) sdmmc_cmd: Card is SD
E (1022) sdmmc_cmd: Retry Num : 42
E (1022) sdmmc_cmd: Card is SD
E (1032) sdmmc_cmd: Retry Num : 41
E (1032) sdmmc_cmd: Card is SD
E (1042) sdmmc_cmd: Retry Num : 40
E (1042) sdmmc_cmd: Card is SD
E (1052) sdmmc_cmd: Retry Num : 39
E (1052) sdmmc_cmd: Card is SD
E (1062) sdmmc_cmd: Retry Num : 38
E (1062) sdmmc_cmd: Card is SD
E (1072) sdmmc_cmd: Retry Num : 37
E (1072) sdmmc_cmd: Card is SD
E (1082) sdmmc_cmd: Retry Num : 36
E (1082) sdmmc_cmd: Card is SD
E (1092) sdmmc_cmd: Retry Num : 35
E (1092) sdmmc_cmd: Card is SD
E (1102) sdmmc_cmd: Retry Num : 34
E (1102) sdmmc_cmd: Card is SD
E (1112) sdmmc_cmd: Retry Num : 33
E (1112) sdmmc_cmd: Card is SD
E (1122) sdmmc_cmd: Retry Num : 32
E (1122) sdmmc_cmd: Card is SD
E (1132) sdmmc_cmd: Retry Num : 31
E (1132) sdmmc_cmd: Card is SD
E (1142) sdmmc_cmd: Retry Num : 30
E (1142) sdmmc_cmd: Card is SD
E (1152) sdmmc_cmd: Retry Num : 29
E (1152) sdmmc_cmd: Card is SD
E (1162) sdmmc_cmd: Retry Num : 28
E (1162) sdmmc_cmd: Card is SD
E (1172) sdmmc_cmd: Retry Num : 27
E (1172) sdmmc_cmd: Card is SD
E (1182) sdmmc_cmd: Retry Num : 26
E (1182) sdmmc_cmd: Card is SD
E (1192) sdmmc_cmd: Retry Num : 25
E (1192) sdmmc_cmd: Card is SD
E (1202) sdmmc_cmd: Retry Num : 24
E (1202) sdmmc_cmd: Card is SD
E (1212) sdmmc_cmd: Retry Num : 23
E (1212) sdmmc_cmd: Card is SD
E (1222) sdmmc_cmd: Retry Num : 22
E (1222) sdmmc_cmd: Card is SD
E (1232) sdmmc_cmd: Retry Num : 21
E (1232) sdmmc_cmd: Card is SD
E (1242) sdmmc_cmd: Retry Num : 20
E (1242) sdmmc_cmd: Card is SD
E (1252) sdmmc_cmd: Retry Num : 19
E (1252) sdmmc_cmd: Card is SD
E (1262) sdmmc_cmd: Retry Num : 18
E (1262) sdmmc_cmd: Card is SD
E (1272) sdmmc_cmd: Retry Num : 17
E (1272) sdmmc_cmd: Card is SD
E (1282) sdmmc_cmd: Retry Num : 16
E (1282) sdmmc_cmd: Card is SD
E (1292) sdmmc_cmd: Retry Num : 15
E (1292) sdmmc_cmd: Card is SD
E (1302) sdmmc_cmd: Retry Num : 14
E (1302) sdmmc_cmd: Card is SD
E (1312) sdmmc_cmd: Retry Num : 13
E (1312) sdmmc_cmd: Card is SD
E (1322) sdmmc_cmd: Retry Num : 12
E (1322) sdmmc_cmd: Card is SD
E (1332) sdmmc_cmd: Retry Num : 11
E (1332) sdmmc_cmd: Card is SD
E (1342) sdmmc_cmd: Retry Num : 10
E (1342) sdmmc_cmd: Card is SD
E (1352) sdmmc_cmd: Retry Num : 9
E (1352) sdmmc_cmd: Card is SD
E (1362) sdmmc_cmd: Retry Num : 8
E (1362) sdmmc_cmd: Card is SD
E (1372) sdmmc_cmd: Retry Num : 7
E (1372) sdmmc_cmd: Card is SD
E (1382) sdmmc_cmd: Retry Num : 6
E (1382) sdmmc_cmd: Card is SD
E (1392) sdmmc_cmd: Retry Num : 5
E (1392) sdmmc_cmd: Card is SD
E (1402) sdmmc_cmd: Retry Num : 4
E (1402) sdmmc_cmd: Card is SD
E (1412) sdmmc_cmd: Retry Num : 3
E (1412) sdmmc_cmd: Card is SD
E (1422) sdmmc_cmd: Retry Num : 2
E (1422) sdmmc_cmd: Card is SD
E (1432) sdmmc_cmd: Retry Num : 1
E (1432) sdmmc_cmd: Card is SD
E (1442) sdmmc_cmd: After Retries, Error : 0x0
E (1442) sdmmc_cmd: ESP_ERR_TIMOUT in sdmmc_send_cmd_send_op_cond
E (1442) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107
E (1442) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).
I (1452) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
E (1462) example: Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place.
I (1472) main_task: Returned from app_main()
Mind you, this behaviour only occurs with the SL32G SD card, the Adata cards hang immedietly and irrecoverably.
Since you are using ESP32-S3-WROOM-2, one thing to check: you aren't using GPIO47 and GPIO48 for the SPI bus, right?
No that SPI Bus uses GPIO17, 18 and 8 for MOSI, MISO and SCLK respectively.
No that SPI Bus uses GPIO17, 18 and 8 for MOSI, MISO and SCLK respectively.
There is no problem with this GPIO.
CS's GPIO7 probably doesn't work properly.
CS's GPIO7 probably doesn't work properly.
Why would that be the case?
I connected GPIO17, 18, and 8 for MOSI, MISO, and SCLK.
And I changed the CS as follows.
-
CS is GPIO39 ---> OK I (357) gpio: GPIO[39]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (367) sdspi_transaction: cmd=52, R1 response: command not supported I (417) sdspi_transaction: cmd=5, R1 response: command not supported I (457) example: Filesystem mounted Name: SL32G Type: SDHC/SDXC Speed: 20.00 MHz (limit: 20.00 MHz) Size: 30436MB CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9 SSR: bus_width=1
-
CS is GPIO38 ---> OK I (357) gpio: GPIO[38]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (367) sdspi_transaction: cmd=52, R1 response: command not supported I (417) sdspi_transaction: cmd=5, R1 response: command not supported I (457) example: Filesystem mounted Name: SL32G Type: SDHC/SDXC Speed: 20.00 MHz (limit: 20.00 MHz) Size: 30436MB CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9 SSR: bus_width=1
-
CS is GPIO2 ---> OK I (357) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (367) sdspi_transaction: cmd=52, R1 response: command not supported I (417) sdspi_transaction: cmd=5, R1 response: command not supported I (457) example: Filesystem mounted Name: SL32G Type: SDHC/SDXC Speed: 20.00 MHz (limit: 20.00 MHz) Size: 30436MB CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9 SSR: bus_width=1
-
CS is GPIO7 ---> NG I (357) gpio: GPIO[7]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 E (387) vfs_fat_sdmmc: sdmmc_card_init failed (0x107). I (387) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 E (387) example: Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place.
-
CS is GPIO12 ---> OK I (357) gpio: GPIO[12]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (367) sdspi_transaction: cmd=52, R1 response: command not supported I (417) sdspi_transaction: cmd=5, R1 response: command not supported I (457) example: Filesystem mounted Name: SL32G Type: SDHC/SDXC Speed: 20.00 MHz (limit: 20.00 MHz) Size: 30436MB CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9 SSR: bus_width=1
-
CS is GPIO6 ---> OK I (357) gpio: GPIO[6]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (367) sdspi_transaction: cmd=52, R1 response: command not supported I (417) sdspi_transaction: cmd=5, R1 response: command not supported I (457) example: Filesystem mounted Name: SL32G Type: SDHC/SDXC Speed: 20.00 MHz (limit: 20.00 MHz) Size: 30436MB CSD: ver=2, sector_size=512, capacity=62333952 read_bl_len=9 SSR: bus_width=1
I don't know why.
I found that an error occurs with certain SD-CARDs.
That is certainly valuable information, for both future potential SD Cards to use and the potential pins we might want to use for the SD Card slot...
This however still makes me wonder, why do some SD Cards behave differently? Are there some weird vendor specifics that aren't working correctly with esp-idf?
It also makes me wonder what the breaking change was between idf v4.4 and 5.1.1 to cause the GPIO7 pin to not work correctly as a CS.
We might have to redesign part of the board, as we can't just move it to a different GPIO except for maybe a strapping pin.
We know it works with the SDMMC driver, however using that might cause an issue as we have an ethernet controller (W5500) on the same bus... can SDMMC and SPI Master run in paralell?
Are there some weird vendor specifics that aren't working correctly with esp-idf?
The current consumption of the SD-CARD may have an effect. Previously, in another project, I encountered a problem due to the current consumption of a specific SD-CARD.
however using that might cause an issue as we have an ethernet controller (W5500) on the same bus
This might help. https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/peripherals/sdspi_share.html
can SDMMC and SPI Master run in paralell?
I have not tried it, but I think it would be difficult to operate SDMMC and SPI-MASTER on the same SPI-BUS.
In the mean time we tried using GPIO0, as that is one of the very few pins we don't actively use, and while the CS did trigger correctly the same timeout behavior occured while using that one:
I (381) example: Using SPI peripheral
I (381) example: Mounting filesystem
I (391) gpio: GPIO[0]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (401) sdspi_transaction: cmd=52, R1 response: command not supported
I (441) sdspi_transaction: cmd=5, R1 response: command not supported
E (1441) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107
E (1441) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).
I (1441) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
E (1451) example: Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place.
I (1461) main_task: Returned from app_main()
The same behavior was also observable on GPIO38. We also captured this on our scope:
This looks normal, as the rapid retries are about 1 every 10ms and that 100 times.
This also applies to GPIO39. We believe it is an issue with the SDSPI driver or maybe the drive strength of those pins?
Could you try running a configuration that worked for SDSPI with v5.1.1-229-ga9aea676e7-dirty on the 5.1.1 version that is most recent? @nopnop2002
$ idf.py --version
ESP-IDF v5.1.1
I (0) cpu_start: App cpu up.
I (204) cpu_start: Pro cpu start user code
I (204) cpu_start: cpu freq: 160000000 Hz
I (204) cpu_start: Application information:
I (207) cpu_start: Project name: sd_card
I (212) cpu_start: App version: v5.1.1
I (217) cpu_start: Compile time: Oct 31 2023 04:38:51
I (223) cpu_start: ELF file SHA256: 8541526641380c21...
I (229) cpu_start: ESP-IDF: v5.1.1
I (234) cpu_start: Min chip rev: v0.0
I (239) cpu_start: Max chip rev: v0.99
I (243) cpu_start: Chip rev: v0.1
I (248) heap_init: Initializing. RAM available for dynamic allocation:
I (255) heap_init: At 3FC96540 len 000531D0 (332 KiB): DRAM
I (262) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (268) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (274) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
I (282) spi_flash: detected chip: gd
I (285) spi_flash: flash io: dio
W (289) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (302) sleep: Configure to isolate all GPIO pins in sleep state
I (309) sleep: Enable automatic switching of GPIO sleep configuration
I (316) app_start: Starting scheduler on CPU0
I (321) app_start: Starting scheduler on CPU1
I (321) main_task: Started on CPU0
I (331) main_task: Calling app_main()
I (331) example: Initializing SD card
I (341) example: Using SPI peripheral
I (341) example: Mounting filesystem
I (351) gpio: GPIO[34]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (361) sdspi_transaction: cmd=52, R1 response: command not supported
I (401) sdspi_transaction: cmd=5, R1 response: command not supported
I (421) example: Filesystem mounted
Name: SD16G
Type: SDHC/SDXC
Speed: 20.00 MHz (limit: 20.00 MHz)
Size: 14804MB
CSD: ver=2, sector_size=512, capacity=30318592 read_bl_len=9
SSR: bus_width=1
I (421) example: Opening file /sdcard/hello.txt
I (461) example: File written
I (461) example: Renaming file /sdcard/hello.txt to /sdcard/foo.txt
I (471) example: Reading file /sdcard/foo.txt
I (471) example: Read from file: 'Hello SD16G!'
I (471) vfs_fat_sdmmc: Formatting card, allocation unit size=16384
I (6781) example: file doesnt exist, format done
I (6781) example: Opening file /sdcard/nihao.txt
I (6791) example: File written
I (6791) example: Reading file /sdcard/nihao.txt
I (6801) example: Read from file: 'Nihao SD16G!'
I (6801) gpio: GPIO[34]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (6811) example: Card unmounted
I (6811) gpio: GPIO[17]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (6821) gpio: GPIO[18]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (6831) gpio: GPIO[8]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (6841) main_task: Returned from app_main()
Seeing from the schematic you provided, not all data pins of the card are correctly pulled up, are they?
I mean ALL except clock, including unused pins, DAT1 and DAT2.
SD physical layer specification v3.0.1 chapter 6 have requirement for this. And it clearly states that this also applies for SPI mode. Violating this rule may cause unpredictable behavior, including CRC error or timeout. Cards' behavior may relates to model and vendor of the card. (Sorry because the spec is not public, I can't paste it here)
Suggest to make everything compliant to the spec to reduce waste of time.
And regarding to the PCB design, not only short cables are required, low impedance are also required. Not only for the data lines, but also for grounding. Jumping wires are very likely to cause unstable communications. It's highly recommended to provide grounding plate instead of grounding wire between ESP32 and the card.
Seeing from the schematic you provided, not all data pins of the card are correctly pulled up, are they?
I mean ALL except clock, including unused pins, DAT1 and DAT2.
SD physical layer specification v3.0.1 chapter 6 have requirement for this. And it clearly states that this also applies for SPI mode. Violating this rule may cause unpredictable behavior, including CRC error or timeout. Cards' behavior may relates to model and vendor of the card. (Sorry because the spec is not public, I can't paste it here)
We tried this on our board and it didn't make a difference, we haven't set up a seperate test board to test it in isolation yet, however the only device it shares the bus with has been physically disabled. However if it really is a proper Hardware Issue, it shouldn't work at all from what I can gather, even with sdmmc, however sdmmc does work with our setup.
Also the older Driver from v4.4 works, which also shouldn't be the case if there was an issue with the hardware.
And regarding to the PCB design, not only short cables are required, low impedance are also required. Not only for the data lines, but also for grounding. Jumping wires are very likely to cause unstable communications. It's highly recommended to provide grounding plate instead of grounding wire between ESP32 and the card.
This shouldn't be an issue on our PCB, the distance is only about 8cm of copper traces between the µc and the SD Card Slot, with a common ground plate between them, and every other low voltage device on that board.
We attempted it using an ESP32-S3-Korvo-2 Board where we simply soldered a CS Wire to GPIO3 and attempted using it with idf v.5.1.1 and the same behavior persisted, it worked using sdmmc, just like the custom board.
The modified Corvo Board
As sdmmc and sdspi are electrically identical, except for the lack of a CS on sdmmc, we conclude that there is likely an issue in the currently available versions of IDF v5.1.1, we do not know why it seems that nopnop is unable to replicate it unless using GPIO7 as a CS however.
It seems likely that we have to redesign our custom board unless this issue is fixed.
@dmglogowskiOS
I'm not sure if this has anything to do with your problem.
https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/peripherals/sd_pullup_requirements.html
@nopnop2002
We are pretty sure that isn't the issue as we have already added the necessary pullups and checked and rechecked their connection multiple times.
However we would like to know what dev board(s) you use to test so we can attempt to replicate your results.