espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.37k stars 7.21k forks source link

esp32s3 sdmmc_init_ocr: send_op_cond (1) returned 0x107 (IDFGH-10167) #11438

Open LazzyMozzie opened 1 year ago

LazzyMozzie commented 1 year ago

Answers checklist.

IDF version.

V4.4.4

Operating System used.

Linux

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

None

Development Kit.

CustomBoard - ESP32S3

Power Supply used.

External 5V

What is the expected behavior?

when system is repoered or softrest, the sdcard running normally.

What is the actual behavior?

when system is repoered or softrest, there is a probability thad sdcard does not respond, and return the error :

E (832) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107 D (832) sdmmc_init: sdmmc_card_init: sdmmc_init_ocr returned 0x107 E (832) vfs_fat_sdmmc: sdmmc_card_init failed (0x107). E (832) SD_FLASH: [../components/sd_flash/sd_flash.c:141] Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place. E (832) DataReupload: [../main/data_reupload/data_reupload.c:464] SD card init failed ....

Steps to reproduce.

when system is up normally, and the sdcard is also running well, I repower the board or softreset the system, the porblem is going to come up

the code is:

  1. I used 1-line mode, and other data line [1-3] also has pull up resistance
  2. I used external pull-up resistance (i has disable internal pull-up, but it semms not come into effect, the log gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0)
  3. now i set sdio speed is 1M, it seem has no effect
    
    #include <string.h>
    #include <sys/unistd.h>
    #include <sys/stat.h>
    #include "esp_vfs_fat.h"
    #include "sdmmc_cmd.h"
    #include "driver/sdmmc_host.h"
    #include "ulog.h"

define TAG "SD_FLASH"

define MOUNT_POINT "/sdcard"

define CONFIG_EXAMPLE_FORMAT_IF_MOUNT_FAILED

// #define CONFIG_EXAMPLE_SDMMC_BUS_WIDTH_4

define CONFIG_SOC_SDMMC_USE_GPIO_MATRIX

define CONFIG_EXAMPLE_PIN_CMD GPIO_NUM_35

define CONFIG_EXAMPLE_PIN_CLK GPIO_NUM_36

define CONFIG_EXAMPLE_PIN_D0 GPIO_NUM_37

define CONFIG_EXAMPLE_PIN_D1 GPIO_NUM_38

define CONFIG_EXAMPLE_PIN_D2 GPIO_NUM_33

define CONFIG_EXAMPLE_PIN_D3 GPIO_NUM_34

static sdmmc_card_t *card = NULL; int sd_flash_init(void) { esp_err_t ret;

// Options for mounting the filesystem.
// If format_if_mount_failed is set to true, SD card will be partitioned and
// formatted in case when mounting fails.
esp_vfs_fat_sdmmc_mount_config_t mount_config = {

ifdef CONFIG_EXAMPLE_FORMAT_IF_MOUNT_FAILED

    .format_if_mount_failed = true,

else

    .format_if_mount_failed = false,

endif // EXAMPLE_FORMAT_IF_MOUNT_FAILED

    .max_files = 5,
    .allocation_unit_size = 512};

const char mount_point[] = MOUNT_POINT;
HK_LOG_I(TAG, "Initializing SD card");

// Use settings defined above to initialize SD card and mount FAT filesystem.
// Note: esp_vfs_fat_sdmmc/sdspi_mount is all-in-one convenience functions.
// Please check its source code and implement error recovery when developing
// production applications.

HK_LOG_I(TAG, "Using SDMMC peripheral");

// By default, SD card frequency is initialized to SDMMC_FREQ_DEFAULT (20MHz)
// For setting a specific frequency, use host.max_freq_khz (range 400kHz - 40MHz for SDMMC)
// Example: for fixed frequency of 10MHz, use host.max_freq_khz = 10000;
sdmmc_host_t host = SDMMC_HOST_DEFAULT();
host.max_freq_khz = 1000;

// This initializes the slot without card detect (CD) and write protect (WP) signals.
// Modify slot_config.gpio_cd and slot_config.gpio_wp if your board has these signals.

sdmmc_slot_config_t slot_config = SDMMC_SLOT_CONFIG_DEFAULT();
// sdmmc_slot_config_t slot_config;

// gpio_set_pull_mode(CONFIG_EXAMPLE_PIN_CMD, GPIO_PULLUP_ONLY);   // CMD, needed in 4- and 1- line modes
// gpio_set_pull_mode(CONFIG_EXAMPLE_PIN_D0, GPIO_PULLUP_ONLY);    // D0, needed in 4- and 1-line modes
// gpio_set_pull_mode(CONFIG_EXAMPLE_PIN_D1, GPIO_PULLUP_ONLY);    // D1, needed in 4- and 1-line modes
// gpio_set_pull_mode(CONFIG_EXAMPLE_PIN_D2, GPIO_PULLUP_ONLY);    // D1, needed in 4- and 1-line modes
// gpio_set_pull_mode(CONFIG_EXAMPLE_PIN_D3, GPIO_PULLUP_ONLY);    // D1, needed in 4- and 1-line modes

// Set bus width to use:

ifdef CONFIG_EXAMPLE_SDMMC_BUS_WIDTH_4

slot_config.width = 4;

else

slot_config.width = 1;

endif

// On chips where the GPIOs used for SD card can be configured, set them in
// the slot_config structure:

ifdef CONFIG_SOC_SDMMC_USE_GPIO_MATRIX

slot_config.clk = CONFIG_EXAMPLE_PIN_CLK;
slot_config.cmd = CONFIG_EXAMPLE_PIN_CMD;
slot_config.d0 = CONFIG_EXAMPLE_PIN_D0;

ifdef CONFIG_EXAMPLE_SDMMC_BUS_WIDTH_4

slot_config.d1 = CONFIG_EXAMPLE_PIN_D1;
slot_config.d2 = CONFIG_EXAMPLE_PIN_D2;
slot_config.d3 = CONFIG_EXAMPLE_PIN_D3;

endif // CONFIG_EXAMPLE_SDMMC_BUS_WIDTH_4

endif // CONFIG_SOC_SDMMC_USE_GPIO_MATRIX

// Enable internal pullups on enabled pins. The internal pullups
// are insufficient however, please make sure 10k external pullups are
// connected on the bus. This is for debug / example purpose only.
// slot_config.flags |= SDMMC_SLOT_FLAG_INTERNAL_PULLUP;
vTaskDelay(100/portTICK_RATE_MS); //重新上电或者复位后,休眠100ms,等待电源稳定
HK_LOG_I(TAG, "Mounting filesystem");
ret = esp_vfs_fat_sdmmc_mount(mount_point, &host, &slot_config, &mount_config, &card);

if (ret != ESP_OK)
{
    if (ret == ESP_FAIL)
    {
        HK_LOG_E(TAG, "Failed to mount filesystem. "
                      "If you want the card to be formatted, set the EXAMPLE_FORMAT_IF_MOUNT_FAILED menuconfig option.");
    }
    else
    {
        HK_LOG_E(TAG, "Failed to initialize the card (%s). "
                      "Make sure SD card lines have pull-up resistors in place.",
                 esp_err_to_name(ret));
    }

    return -1;
}

HK_LOG_I(TAG, "Filesystem mounted");

// Card has been initialized, print its properties
sdmmc_card_print_info(stdout, card);
sd_get_usage(NULL, NULL);
return 0;

}


### Debug Logs.

```plain
Waiting for the device to reconnect.
I (377) esp_image: segment 4: paddr=001c880c vaddr=4037b9ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x42094b82
0x42094b82: esp_pm_impl_waiti at /home/yan/esp/esp-idf/components/esp_pm/pm_impl.c:839

SPIWP:0xee
mode:DOUT, clock div:2
load:0x3fce3808,len:0x17b4
load:0x403c9700,len:0xcd8
load:0x403cc700,len:0x2eb4
entry 0x403c9970
I (29) boot: ESP-IDF v4.4.4-dirty 2nd stage bootloader
I (30) boot: compile time 10:44:22
I (30) boot: chip revision: v0.1
I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DOUT
I (49) boot.esp32s3: SPI Flash Size : 8MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (77) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (84) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (92) boot:  3 coredump         Unknown data     01 03 00010000 00010000
I (99) boot:  4 test             test app         00 20 00020000 000e0000
I (107) boot:  5 ota_0            OTA app          00 10 00100000 00180000
I (114) boot:  6 ota_1            OTA app          00 11 00280000 00180000
I (122) boot: End of partition table
I (126) boot_comm: chip revision: 1, min. application chip revision: 0
I (133) esp_image: segment 0: paddr=00100020 vaddr=3c0a0020 size=23f0ch (147212) map
I (182) esp_image: segment 1: paddr=00123f34 vaddr=3fc98980 size=04768h ( 18280) load
I (188) esp_image: segment 2: paddr=001286a4 vaddr=40374000 size=07974h ( 31092) load
I (198) esp_image: segment 3: paddr=00130020 vaddr=42000020 size=987e4h (624612) map
I (370) esp_image: segment 4: paddr=001c880c vaddr=4037b974 size=0d00ch ( 53260) load
I (395) boot: Loaded app from partition at offset 0x100000
I (395) boot: Disabling RNG early entropy source...
D (396) flash HPM: HPM with dummy, status is 3
I (400) cpu_start: Pro cpu up.
I (404) cpu_start: Starting app cpu, entry point is 0x403753f4
0x403753f4: call_start_cpu1 at /home/yan/esp/esp-idf/components/esp_system/port/cpu_start.c:148

I (0) cpu_start: App cpu up.
D (411) efuse: In EFUSE_BLK1__DATA3_REG is used 3 bits starting with 24 bit
D (411) efuse: In EFUSE_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (411) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (412) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (412) efuse: In EFUSE_BLK1__DATA5_REG is used 5 bits starting with 11 bit
D (413) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (413) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (414) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (414) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (414) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (415) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 13 bit
D (415) efuse: In EFUSE_BLK1__DATA4_REG is used 7 bits starting with 20 bit
D (416) efuse: In EFUSE_BLK1__DATA4_REG is used 5 bits starting with 27 bit
D (416) efuse: In EFUSE_BLK1__DATA5_REG is used 3 bits starting with 0 bit
D (417) efuse: In EFUSE_BLK1__DATA5_REG is used 8 bits starting with 3 bit
D (425) clk: RTC_SLOW_CLK calibration value: 4022438
I (426) cpu_start: Pro cpu start user code
I (426) cpu_start: cpu freq: 160000000
I (426) cpu_start: Application information:
I (427) cpu_start: Project name:     coevos_pho
I (427) cpu_start: App version:      V1R2C2.0513
I (427) cpu_start: Compile time:     May 19 2023 10:44:18
I (427) cpu_start: ELF file SHA256:  7db69009fad26d7b...
I (427) cpu_start: ESP-IDF:          v4.4.4-dirty
D (428) memory_layout: Checking 5 reserved memory ranges:
D (428) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc98980
D (428) memory_layout: Reserved memory range 0x3fc98980 - 0x3fca2608
D (428) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (429) memory_layout: Reserved memory range 0x40374000 - 0x40388980
0x40374000: _WindowOverflow4 at /home/yan/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1739

D (429) memory_layout: Reserved memory range 0x600fe000 - 0x600fe000
D (429) memory_layout: Building list of available memory regions:
D (430) memory_layout: Available memory region 0x3fca2608 - 0x3fcb0000
D (430) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (430) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (431) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (431) memory_layout: Available memory region 0x3fce0000 - 0x3fce9710
D (431) memory_layout: Available memory region 0x3fce9710 - 0x3fceee34
D (432) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (432) memory_layout: Available memory region 0x600fe000 - 0x60100000
I (432) heap_init: Initializing. RAM available for dynamic allocation:
D (433) heap_init: New heap initialised at 0x3fca2608
I (433) heap_init: At 3FCA2608 len 00047108 (284 KiB): D/IRAM
I (433) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
D (434) heap_init: New heap initialised at 0x3fcf0000
I (434) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (434) heap_init: New heap initialised at 0x600fe000
I (434) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
D (435) FLASH_HAL: extra_dummy: 0
D (436) spi_flash: trying chip: issi
D (436) spi_flash: trying chip: gd
I (437) spi_flash: detected chip: gd
I (437) spi_flash: flash io: dout
D (437) cpu_start: calling init function: 0x4207d1e8
0x4207d1e8: _GLOBAL__sub_I___cxa_get_globals_fast at /builds/idf/crosstool-NG/.build/xtensa-esp32s3-elf/src/gcc/libstdc++-v3/libsupc++/eh_globals.cc:145

D (437) cpu_start: calling init function: 0x4202cd4c
0x4202cd4c: s_set_default_wifi_log_level at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_init.c:63

D (437) cpu_start: calling init function: 0x4201b31c
0x4201b31c: esp_ipc_init at /home/yan/esp/esp-idf/components/esp_ipc/src/esp_ipc.c:105

D (438) cpu_start: calling init function: 0x42003318
0x42003318: esp_ota_init_app_elf_sha256 at /home/yan/esp/esp-idf/components/app_update/esp_app_desc.c:68

D (439) intr_alloc: Connected src 59 to int 2 (cpu 0)
I (439) sleep: Configure to isolate all GPIO pins in sleep state
I (439) sleep: Enable automatic switching of GPIO sleep configuration
D (440) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (440) cpu_start: Starting scheduler on PRO CPU.
D (441) intr_alloc: Connected src 57 to int 9 (cpu 0)
D (441) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (441) cpu_start: Starting scheduler on APP CPU.
D (441) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (441) heap_init: New heap initialised at 0x3fce9710
D (441) intr_alloc: Connected src 52 to int 12 (cpu 0)
D (441) partition: Loading the partition table
D (441) partition: Partition table MD5 verified
D (471) nvs: nvs_open_from_partition dbns 1
D (471) intr_alloc: Connected src 42 to int 13 (cpu 0)
I (491) MAIN: [../main/main.c:52] PCF_systohc() ok!
D (491) nvs: nvs_get_str_or_blob PHO_SN
I (491) ID_MANAGE: [../components/id_manage/id_manage.c:120] sn = ZSNFC1001Z
D (491) nvs: nvs_get_str_or_blob M_PHO_SN
I (491) ID_MANAGE: [../components/id_manage/id_manage.c:122] master sn = ZSNFC1001Z
D (491) nvs: nvs_get PHO_ID 1
D (491) nvs: nvs_get PHO_ID 1
I (491) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (491) gpio: GPIO[5]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (491) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (491) gpio: GPIO[46]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (491) ID_MANAGE: [../components/id_manage/id_manage.c:141] ids id = 1
I (501) RIL: [../main/cloud_data_sync/mqtt_task.c:468] Master mode! exec mqtt_task_init()
I (501) gpio: GPIO[40]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
D (501) intr_alloc: Connected src 28 to int 17 (cpu 0)
D (501) nvs: nvs_get PHO_ID 1
I (501) message dispatch: [../components/message_dispatch/message_dispatch.c:326] thread name[msg_dispatch_thread[0]]
D (501) nvs: nvs_get PHO_ID 1
I (501) RIL: [../main/cloud_data_sync/mqtt_task.c:127] topic_store:dev/push/ZSNFC1001Z
D (501) nvs: nvs_get PHO_ID 1
I (501) RIL: [../main/cloud_data_sync/mqtt_task.c:127] topic_store:dev/in/ZSNFC1001Z
I (501) system_api: Base MAC address is not set
D (501) nvs: nvs_get PHO_ID 1
I (501) system_api: read default base MAC address from EFUSE
D (501) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (501) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (501) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (511) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (511) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (511) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (511) nvs: nvs_get PHO_ID 1
I (511) RIL: [../main/cloud_data_sync/mqtt_task.c:326] mqtt client id: [ZSNFC1001Z_DC5475C429B9].
D (511) nvs: nvs_get PHO_ID 1
I (511) RIL: [../main/cloud_data_sync/mqtt_task.c:202] mqtt will message:[{"body":{"status":"offline"},"event":"online_status","devid":"ZSNFC1001Z"}
].
I (511) wireless: [../main/wireless/wireless.c:287] Master mode! exec wifi_init_softap()
D (511) nvs: nvs_get PHO_ID 1
I (511) wireless: [../main/wireless/wireless.c:184] ssid:IDS_ZSNFC1001Z, calc ids wifi password is:a5343f08b948

D (511) esp_netif_lwip: LwIP stack has been initialized
D (511) esp_netif_lwip: esp-netif has been successfully initialized
I (521) RIL: [../main/cloud_data_sync/ril_task.c:74] RIL_PIN_RESET:0
D (521) event: running task for loop 0x3fca8880
D (521) event: created task for loop 0x3fca8880
D (521) event: created event loop 0x3fca8880
D (521) esp_netif_objects: esp_netif_add_to_list 0x3fca97ac
D (521) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (521) esp_netif_objects: esp_netif_add_to_list 0x3fca9b78
D (521) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (521) pp: pp rom version: e7ae62f
I (521) net80211: net80211 rom version: e7ae62f
D (521) nvs: nvs_open_from_partition misc 1
I (531) wifi:wifi driver task: 3fcac3b0, prio:23, stack:6656, core=0
D (531) nvs: nvs_open_from_partition nvs.net80211 1
D (531) nvs: nvs_get opmode 1
D (531) nvs: nvs_get_str_or_blob sta.ssid
D (531) nvs: nvs_get sta.authmode 1
D (531) nvs: nvs_get_str_or_blob sta.pswd
D (531) nvs: nvs_get_str_or_blob sta.pmk
D (531) nvs: nvs_get sta.chan 1
D (531) nvs: nvs_get auto.conn 1
D (531) nvs: nvs_get bssid.set 1
D (531) nvs: nvs_get_str_or_blob sta.bssid
D (531) nvs: nvs_get sta.lis_intval 2
D (531) nvs: nvs_get sta.phym 1
D (531) nvs: nvs_get sta.phybw 1
D (531) nvs: nvs_get_str_or_blob sta.apsw
D (541) nvs: nvs_get_str_or_blob sta.apinfo
D (541) nvs: nvs_get sta.scan_method 1
D (541) nvs: nvs_get sta.sort_method 1
D (541) nvs: nvs_get sta.minrssi 1
D (541) nvs: nvs_get sta.minauth 1
D (541) nvs: nvs_get sta.pmf_e 1
D (541) nvs: nvs_get sta.pmf_r 1
D (541) nvs: nvs_get sta.btm_e 1
D (541) nvs: nvs_get sta.rrm_e 1
D (541) nvs: nvs_get sta.mbo_e 1
D (541) nvs: nvs_get_str_or_blob ap.ssid
D (541) nvs: nvs_get_str_or_blob ap.passwd
D (551) nvs: nvs_get_str_or_blob ap.pmk
D (551) nvs: nvs_get ap.chan 1
D (551) nvs: nvs_get ap.authmode 1
D (551) nvs: nvs_get ap.hidden 1
D (551) nvs: nvs_get ap.max.conn 1
D (551) nvs: nvs_get bcn.interval 2
D (551) nvs: nvs_get ap.phym 1
D (551) nvs: nvs_get ap.phybw 1
D (551) nvs: nvs_get ap.sndchan 1
D (551) nvs: nvs_get ap.pmf_e 1
D (551) nvs: nvs_get ap.pmf_r 1
D (551) nvs: nvs_get ap.p_cipher 1
D (551) nvs: nvs_get lorate 1
D (551) nvs: nvs_get_str_or_blob country
D (551) nvs: nvs_get ap.ftm_r 1
D (551) nvs: nvs_set ap.sndchan 1 1
I (551) wifi:wifi firmware version: 6567a16
I (551) wifi:wifi certification version: v7.0
I (551) wifi:config NVS flash: enabled
I (551) wifi:config nano formating: disabled
I (551) wifi:Init data frame dynamic rx buffer num: 32
I (561) wifi:Init management frame dynamic rx buffer num: 32
I (561) wifi:Init management short buffer num: 32
I (561) wifi:Init dynamic tx buffer num: 32
I (561) wifi:Init static tx FG buffer num: 2
I (561) wifi:Init static rx buffer size: 1600
I (561) wifi:Init static rx buffer num: 10
I (561) wifi:Init dynamic rx buffer num: 32
I (561) wifi_init: rx ba win: 6
I (561) wifi_init: tcpip mbox: 32
I (561) wifi_init: udp mbox: 6
I (561) wifi_init: tcp mbox: 6
I (561) wifi_init: tcp tx win: 5744
I (561) wifi_init: tcp rx win: 5744
I (561) wifi_init: tcp mss: 1440
I (561) wifi_init: WiFi IRAM OP enabled
I (561) wifi_init: WiFi RX IRAM OP enabled
D (561) ADC: Wi-Fi takes adc2 lock.
I (561) phy_init: phy_version 540,a5d905b,Oct 20 2022,19:36:11
D (561) phy_init: loading PHY init data from application binary
D (561) nvs: nvs_open_from_partition phy 0
D (561) nvs: nvs_get cal_version 4
D (561) nvs: nvs_get_str_or_blob cal_mac
D (561) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (571) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (571) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (571) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (571) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (571) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (571) nvs: nvs_get_str_or_blob cal_data
D (571) nvs: nvs_close 4
D (581) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (581) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (581) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (611) wifi:filter: set rx policy=0
I (611) wifi:mode : softAP (dc:54:75:c4:29:b9)
D (611) wifi:filter: set rx policy=9
D (611) gdma: new group (0) at 0x3fcb21d4
D (611) gdma: new pair (0,0) at 0x3fcb2210
D (611) gdma: new tx channel (0,0) at 0x3fcb21a4
D (611) gdma: new rx channel (0,0) at 0x3fcb2230
D (611) gdma: tx channel (0,0), (1:16) bytes aligned, burst enabled
D (611) gdma: rx channel (0,0), (1:16) bytes aligned, burst disabled
I (621) wifi:Total power save buffer number: 16
I (621) wifi:Init max length of beacon: 752/752
I (621) wifi:Init max length of beacon: 752/752
D (621) event: running post WIFI_EVENT:12 with handler 0x4202d014 and context 0x3fca9ae4 on loop 0x3fca8880
0x4202d014: wifi_default_action_ap_start at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_default.c:108

D (621) wifi_init_default: wifi_start esp-netif:0x3fca9b78 event-id12
D (621) wifi_init_default: WIFI mac address: dc 54 75 c4 29 b9
D (621) esp_netif_handlers: esp_netif action has started with netif0x3fca9b78 from event_id=12
D (621) esp_netif_lwip: check: remote, if=0x3fca9b78 fn=0x4202aab0
0x4202aab0: esp_netif_start_api at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:700

D (621) esp_netif_lwip: esp_netif_start_api 0x3fca9b78
D (621) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fca9b78
[2023-05-19 04:56:10][INFO]: hal_wifi_init_sta_ap@../components/sdkal/src/hal_wifi.c#227: hal_wifi_init_sta_ap finished.
D (621) esp_netif_lwip: esp_netif_start_api Setting the lwip netif0x3fca9bf8 UP
D (631) esp_netif_lwip: DHCP server started successfully
D (631) esp_netif_lwip: check: local, if=0x3fca9b78 fn=0x4202b450
0x4202b450: esp_netif_update_default_netif_lwip at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (631) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca9b78
D (631) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (631) event: running post WIFI_EVENT:12 with handler 0x42019884 and context 0x3fcb1680 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [12]
D (631) wifi:filter: set rx policy=10
D (631) event: running post WIFI_EVENT:13 with handler 0x4202cee0 and context 0x3fca9b14 on loop 0x3fca8880
0x4202cee0: wifi_default_action_ap_stop at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_default.c:115

D (631) esp_netif_handlers: esp_netif action stopped with netif0x3fca9b78 from event_id=13
D (631) esp_netif_lwip: check: remote, if=0x3fca9b78 fn=0x4202ac44
0x4202ac44: esp_netif_stop_api at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:792

I (631) wifi:D (631) esp_netif_lwip: check: local, if=0x3fca9b78 fn=0x4202b450
0x4202b450: esp_netif_update_default_netif_lwip at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

flush txqD (641) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca9b78

D (641) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (641) wifi:stop sw txq
D (641) wifi:filter: set rx policy=0
I (651) wifi:lmac stop hw txq
D (651) ADC: Wi-Fi returns adc2 lock.
D (651) event: running post WIFI_EVENT:13 with handler 0x42019884 and context 0x3fcb1680 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [13]
D (651) ADC: Wi-Fi takes adc2 lock.
D (651) wifi:filter: set rx policy=0
I (661) wifi:mode : softAP (dc:54:75:c4:29:b9)
D (661) wifi:filter: set rx policy=9
I (661) wifi:Total power save buffer number: 16
D (661) event: running post WIFI_EVENT:12 with handler 0x4202d014 and context 0x3fca9ae4 on loop 0x3fca8880
0x4202d014: wifi_default_action_ap_start at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_default.c:108

D (661) wifi_init_default: wifi_start esp-netif:0x3fca9b78 event-id12
D (661) wifi_init_default: WIFI mac address: dc 54 75 c4 29 b9
D (661) esp_netif_handlers: esp_netif action has started with netif0x3fca9b78 from event_id=12
D (661) esp_netif_lwip: check: remote, if=0x3fca9b78 fn=0x4202aab0
0x4202aab0: esp_netif_start_api at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:700

D (661) esp_netif_lwip: esp_netif_start_api 0x3fca9b78
D (661) nvs: nvs_get opmode 1
D (661) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fca9b78
D (671) esp_netif_lwip: esp_netif_start_api Setting the lwip netif0x3fca9bf8 UP
D (671) nvs: nvs_set ap.authmode 1 4
D (671) nvs: nvs_set ap.chan 1 1
D (671) esp_netif_lwip: DHCP server started successfully
D (671) esp_netif_lwip: check: local, if=0x3fca9b78 fn=0x4202b450
0x4202b450: esp_netif_update_default_netif_lwip at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (671) nvs: nvs_set ap.sndchan 1 1
D (671) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca9b78
D (671) wifi:D (671) esp_netif_lwip: call api in lwip: ret=0x0, give sem
filter: set rx policy=10
D (671) nvs: nvs_set_blob ap.ssid 36
D (671) nvs: nvs_set_blob ap.passwd 65
D (671) nvs: nvs_set ap.hidden 1 0
D (681) nvs: nvs_set ap.max.conn 1 15
D (681) nvs: nvs_set bcn.interval 2 100
D (681) nvs: nvs_set ap.p_cipher 1 5
D (681) nvs: nvs_set ap.ftm_r 1 0
D (681) wifi:filter: set rx policy=9
I (681) wifi:Total power save buffer number: 16
D (681) event: running post WIFI_EVENT:12 with handler 0x42019884 and context 0x3fcb1680 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [12]
D (691) event: running post WIFI_EVENT:12 with handler 0x42019884 and context 0x3fcb2260 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [12]
D (691) event: running post WIFI_EVENT:13 with handler 0x4202cee0 and context 0x3fca9b14 on loop 0x3fca8880
0x4202cee0: wifi_default_action_ap_stop at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_default.c:115

D (691) esp_netif_handlers: esp_netif action stopped with netif0x3fca9b78 from event_id=13
D (691) esp_netif_lwip: check: remote, if=0x3fca9b78 fn=0x4202ac44
0x4202ac44: esp_netif_stop_api at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:792

D (691) esp_netif_lwip: check: local, if=0x3fca9b78 fn=0x4202b450
0x4202b450: esp_netif_update_default_netif_lwip at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (691) wifi:D (691) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca9b78
not sta mode, return true
D (691) esp_netif_lwip: call api in lwip: ret=0x0, give sem

D (691) event: running post WIFI_EVENT:13 with handler 0x42019884 and context 0x3fcb1680 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [13]
D (691) event: running post WIFI_EVENT:13 with handler 0x42019884 and context 0x3fcb2260 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [13]
D (691) event: running post WIFI_EVENT:12 with handler 0x4202d014 and context 0x3fca9ae4 on loop 0x3fca8880
0x4202d014: wifi_default_action_ap_start at /home/yan/esp/esp-idf/components/esp_wifi/src/wifi_default.c:108

D (701) wifi_init_default: wifi_start esp-netif:0x3fca9b78 event-id12
D (701) wifi_init_default: WIFI mac address: dc 54 75 c4 29 b9
D (701) esp_netif_handlers: esp_netif action has started with netif0x3fca9b78 from event_id=12
D (701) esp_netif_lwip: check: remote, if=0x3fca9b78 fn=0x4202aab0
0x4202aab0: esp_netif_start_api at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:700

D (701) esp_netif_lwip: esp_netif_start_api 0x3fca9b78
D (701) nvs: nvs_get PHO_ID 1
D (701) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fca9b78
D (701) esp_netif_lwip: esp_netif_start_api Setting the lwip netif0x3fca9bf8 UP
D (701) esp_netif_lwip: DHCP server started successfully
D (701) esp_netif_lwip: check: local, if=0x3fca9b78 fn=0x4202b450
0x4202b450: esp_netif_update_default_netif_lwip at /home/yan/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (701) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca9b78
D (701) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (701) event: running post WIFI_EVENT:12 with handler 0x42019884 and context 0x3fcb1680 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [12]
D (701) event: running post WIFI_EVENT:12 with handler 0x42019884 and context 0x3fcb2260 on loop 0x3fca8880
0x42019884: hal_wifi_event_handler at /home/yan/work/coevos/esp32s3_pho/build/../components/sdkal/src/hal_wifi.c:147

[2023-05-19 04:56:10][INFO]: hal_wifi_wifi_event_handler@../components/sdkal/src/hal_wifi.c#141: wifi event_id [12]
I (711) SD_FLASH: [../components/sd_flash/sd_flash.c:75] Initializing SD card
I (711) SD_FLASH: [../components/sd_flash/sd_flash.c:82] Using SDMMC peripheral
I (721) RIL: [../main/cloud_data_sync/ril_task.c:74] RIL_PIN_RESET:1
I (811) SD_FLASH: [../components/sd_flash/sd_flash.c:127] Mounting filesystem
D (811) sdmmc_periph: peripheral version 5342270a, hardware config 03c44c83
D (811) intr_alloc: Connected src 30 to int 18 (cpu 0)
E (811) sdmmc_periph: -----------use  SOC_SDMMC_USE_GPIO_MATRIX
E (811) sdmmc_periph: -----------pull up en 0
E (811) sdmmc_periph: --------------- pin 1
D (811) sdmmc_periph: using GPIO36 as clk pin
I (811) gpio: GPIO[36]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (811) sdmmc_periph: --------------- pin 2
D (811) sdmmc_periph: using GPIO35 as cmd pin
I (811) gpio: GPIO[35]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (811) sdmmc_periph: --------------- pin 3
D (811) sdmmc_periph: using GPIO37 as d0 pin
I (811) gpio: GPIO[37]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
D (811) sdmmc_periph: slot=1 host_div=10 card_div=20 freq=400kHz
D (811) sdmmc_periph: slot=1 width=1
W (811) vfs_fat_sdmmc: --------------SDIO MODE
D (811) sdmmc_req: process_command_response: error 0x107  (status=00000100)
D (831) sdmmc_sd: SDHC/SDXC card
D (831) sdmmc_req: process_command_response: error 0x107  (status=00000100)
D (831) sdmmc_io: sdmmc_init_io: io_send_op_cond (1) returned 0x107; not IO card
I (921) RIL: [../main/cloud_data_sync/ril_task.c:74] RIL_PIN_RESET:0
D (10831) sdmmc_common: send_op_cond timeout, trying MMC
D (10831) sdmmc_req: process_command_response: error 0x107  (status=00000100)
D (10831) sdmmc_req: process_command_response: error 0x107  (status=00000100)
D (10831) sdmmc_req: process_command_response: error 0x107  (status=00000100)
D (10831) sdmmc_cmd: sdmmc_send_cmd_send_op_cond: sdmmc_send_app_cmd err=0x107
E (10831) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107
D (10831) sdmmc_init: sdmmc_card_init: sdmmc_init_ocr returned 0x107
E (10831) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).
E (10831) SD_FLASH: [../components/sd_flash/sd_flash.c:141] Failed to initialize the card (ESP_ERR_TIMEOUT). Make sure SD card lines have pull-up resistors in place.
E (10831) DataReupload: [../main/data_reupload/data_reupload.c:464] SD card init failed ....

More Information.

No response

igrr commented 1 year ago

This is probably the same issue as https://github.com/espressif/esp-idf/issues/8521. The fix has been merged into release/v4.4 branch in https://github.com/espressif/esp-idf/commit/fb6d9cd7417c90932529c2d83cdc42d5fbd6ff50 and will appear in the next bugfix release, v4.4.5.

LazzyMozzie commented 1 year ago

@igrr hi, i just cherry-pick the commit fb6dc9 to the v4.4.4, it has no effect; And i alos find , the lower the sdio rate, the more likely this problem is to occur

aircable commented 10 months ago

With the latest IDF: git describe --abbrev=0 --tags: v5.2-dev the example storage/sd-card/sdmmc has the same problem, error 0x107, ESP_ERR_TIMEOUT on the ESP32S3_WROOM module. Please note that the Freenove board that uses this module has no connection on the SD card pin 2 (CD). On an older IDF it worked as it should.

suryasid09 commented 9 months ago

Hello @AxelLin @igrr, I have the same issue. But, the board I am using is ESP32-S3-USB-OTG with IDF release v5.2-dev-3775-gb4268c874a. I changed the idf version with v5.1.2, the issue still remains.

JGrossholtz commented 1 week ago

I can confirm the problem with esp-idf 5.2.2 and a custom board using an esp32-s3. After a soft reset the issue goes away.

MrMoDDoM commented 1 week ago

I'm currently facing the same issue with v5.3-369-g466a392a76-dirty, on a custom board with the below schematic, using the Arduino IDE to program the board.

image

An interesting fact is that when I use this function:

esp_err_t mount_sd(gpio_num_t pin_cmd, gpio_num_t pin_clk, gpio_num_t pin_d0, const char* mountpoint, bool format_if_failed, int max_files) {
    esp_err_t res;

    sdmmc_host_t host = SDMMC_HOST_DEFAULT();
    sdmmc_slot_config_t slot_config = SDMMC_SLOT_CONFIG_DEFAULT();

    host.flags = SDMMC_HOST_FLAG_1BIT;
    host.max_freq_khz = 40000;
    slot_config.width = 1;

    gpio_pad_select_gpio(pin_cmd);
    gpio_set_direction(pin_cmd, GPIO_MODE_INPUT_OUTPUT_OD);
    gpio_set_pull_mode(pin_cmd, GPIO_PULLUP_ONLY);
    gpio_set_level(pin_cmd, 1);

    gpio_pad_select_gpio(pin_clk);
    gpio_set_direction(pin_clk, GPIO_MODE_INPUT_OUTPUT_OD);
    gpio_set_pull_mode(pin_clk, GPIO_PULLUP_ONLY);
    gpio_set_level(pin_clk, 1);

    gpio_pad_select_gpio(pin_d0);
    gpio_set_direction(pin_d0,  GPIO_MODE_INPUT_OUTPUT_OD);
    gpio_set_pull_mode(pin_d0,  GPIO_PULLUP_ONLY);
    gpio_set_level(pin_d0,  1);

    esp_vfs_fat_sdmmc_mount_config_t mount_config = {
        .format_if_mount_failed = format_if_failed,
        .max_files              = max_files,
        .allocation_unit_size   = 1024
    };

    res = esp_vfs_fat_sdmmc_mount(mountpoint, &host, &slot_config, &mount_config, &sdcardCard);

    if (res != ESP_OK) {
        if (res == ESP_FAIL) {
            ESP_LOGE(TAG, "Failed to mount the SD card filesystem.");
        } else if (res == ESP_ERR_NO_MEM) {
            ESP_LOGE(TAG, "Failed to initialize the SD card: not enough memory).");
        } else if (res == ESP_ERR_INVALID_RESPONSE) {
            ESP_LOGE(TAG, "Failed to initialize the SD card: invalid response).");
        } else if (res == ESP_ERR_INVALID_STATE) {
            ESP_LOGE(TAG, "Failed to initialize the SD card: invalid state).");
        } else {
            ESP_LOGE(TAG, "Failed to initialize the SD card (%s). ", esp_err_to_name(res));
        }
        return res;
    }
    return res;
}

...the error is ESP_ERR_TIMEOUT

E (1061) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107    
E (1061) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).    
[   563][E][SDMMC_Test.ino:116] mount_sd(): [sdcard] Failed to initialize the SD card (ESP_ERR_TIMEOUT).    

But when I use the example shipped with the ArduinoIDE, the error message does not mention a timeout error:

E (1130) sdmmc_common: sdmmc_init_ocr: send_op_cond (1) returned 0x107
E (1130) vfs_fat_sdmmc: sdmmc_card_init failed (0x107).
[   597][E][SD_MMC.cpp:194] begin(): Failed to initialize the card (0x107). Make sure SD card lines have pull-up resistors in place.

Last thing, when using another SD the error code changes from 0x107 to 0x108.. I'm not completely sure why.

Sadly the soft reset method mentioned by @JGrossholtz has no effects.

igrr commented 1 week ago

@MrMoDDoM In that case your issue is probably unrelated to the one discussed in this ticket. The issue here is specifically for the case (quoting the original report):

when system is re-powered or soft reset, there is a probability thad sdcard does not respond, and return the error

I suggest opening a separate issue, instead.

MrMoDDoM commented 1 week ago

Sorry to bother you further, I just discovered that there was a connection problem with the SD holder, and everything works perfectly on ESP32-S3 with ESP-IDF version v5.3-369-g466a392a76-dirty.

My bad, sorry again.