sdmmc_read_sectors reads 512 byte sector size in 40ms - 50ms (IDFGH-7698)

Environment

Development Kit: ESP32-Wrover-Kit
Kit version (for WroverKit/PicoKit/DevKitC): [v1|v2|v3|v4]
Module or chip used: [ESP32-WROOM-32|
IDF version (run git describe --tags to find it): v5.0-dev-3654-gc2ccc383da
Build System:
CMake
Compiler version (run xtensa-esp32-elf-gcc --version to find it): xtensa-esp32-elf-gcc (crosstool-NG esp-2022r1-RC1) 11.2.0
Operating System: Linux
Using an IDE?: Yes, Clion C++ IDE
Power Supply: [USB|external 5V

Problem Description

Hello, I'm trying to implement little fs on SDMMC interface. The SD card sector size is allowing 512 byte reads at a time. I think the reads function is slower because its spends 40-50 ms for 512kb data reading.

note: sd card interface's spi bus on 20Mhz. 1 Freertos task is running.

is that normal for now?, is there any way to improve that?

[18:14:28:262] Name: SD␍␊ [18:14:28:262] Type: SDHC/SDXC␍␊ [18:14:28:262] Speed: 20 MHz␍␊ [18:14:28:262] Size: 14922MB␍␊ [18:14:28:262] CSD: ver=2, sector_size=512, capacity=30560256 read_bl_len=9␍␊ [18:14:28:262] SSR: bus_width=1␍␊ [18:14:28:278] SD Card block size 512, read len 9, capacity 30560256 [READ]512 byte reading in 50 ms␍␊

Expected Behavior

Actual Behavior

Steps to reproduce

step1
...

// If possible, attach a picture of your setup/wiring here.

Code to reproduce this issue

// the code should be wrapped in the ```cpp tag so that it will be displayed better.
#include "esp_log.h"

#undef CONFIG_LITTLE_FS_IO_DEBUG
/**
 * LittleFS disk io read function
 * @param c littlefs config structure
 * @param block block address
 * @param off offset address
 * @param buffer read buffer
 * @param size read buffer size
 * @return return ok on success
 */
static int lfs_deskio_read(const struct lfs_config *c,
                           lfs_block_t block, lfs_off_t off, void *buffer, lfs_size_t size)
{
    uint32_t current_tick = xTaskGetTickCount();
#ifdef CONFIG_LITTLE_FS_IO_DEBUG
    printf("[READ]block addr %d, offset %d, size %d\n",block, off,size);
#endif
    esp_err_t ret = sdmmc_read_sectors(sdCardInstance, buffer, block, 1);
    if(ret != ESP_OK){
#ifdef CONFIG_LITTLE_FS_IO_DEBUG
        printf("[READ]Error on read, code: %d\n", ret);
#endif
        return LFS_ERR_IO;
    }
#ifdef CONFIG_LITTLE_FS_IO_DEBUG

#endif
    uint32_t elapsed = xTaskGetTickCount() - current_tick;
    elapsed = elapsed * portTICK_PERIOD_MS;
    printf("[READ]512 byte reading in %d ms\n", elapsed);
    return LFS_ERR_OK;
}

#include <string.h>
#include <sys/unistd.h>
#include <sys/stat.h>
#include <driver/rtc_io.h>
#include <esp_task_wdt.h>
#include <driver/spi_common.h>
#include <driver/sdspi_host.h>
#include <esp_log.h>

#include "sdmmc_cmd.h"
#include "lfs_port.h"
extern "C" {
void app_main(void);
}
static const char *TAG = "example";

#define MOUNT_POINT "/sdcard"

#if CONFIG_IDF_TARGET_ESP32S2
#define SPI_DMA_CHAN    host.slot
#elif CONFIG_IDF_TARGET_ESP32C3
#define SPI_DMA_CHAN    SPI_DMA_CH_AUTO
#else
#define SPI_DMA_CHAN    1
#endif

void app_main(void)
{
    rtc_gpio_hold_dis(GPIO_NUM_4);
    esp_err_t ret;
    esp_err_t err = ESP_OK;
    sdmmc_card_t sdCard;
    /*@formatter:off*/
    spi_bus_config_t spiBusConfig = {
            .mosi_io_num = GPIO_NUM_13,
            .miso_io_num = GPIO_NUM_12,
            .sclk_io_num = GPIO_NUM_14,
            .quadwp_io_num = -1,
            .quadhd_io_num = -1,
            .data4_io_num = -1,     ///< GPIO pin for spi data4 signal in octal mode, or -1 if not used.
            .data5_io_num = -1,     ///< GPIO pin for spi data5 signal in octal mode, or -1 if not used.
            .data6_io_num = -1,     ///< GPIO pin for spi data6 signal in octal mode, or -1 if not used.
            .data7_io_num = -1,     ///< GPIO pin for spi data7 signal in octal mode, or -1 if not used.
            .max_transfer_sz = 0, ///< Maximum transfer size, in bytes. Defaults to 4092 if 0 when DMA enabled, or to `SOC_SPI_MAXIMUM_BUFFER_SIZE` if DMA is disabled.
            .flags = 0,                 ///< Abilities of bus to be checked by the driver. Or-ed value of ``SPICOMMON_BUSFLAG_*`` flags.
            .intr_flags = 0
    };/*@formatter:on*/

//Gonna experiment with a seperate SPI device module
    err= spi_bus_initialize(SPI2_HOST, &spiBusConfig, SPI_DMA_CH_AUTO);

    if (err != ESP_OK) {
        ESP_LOGE(TAG, "Failed to init spi2host");
    }
    sdspi_device_config_t SDSPIDeviceConfig = { .host_id = SPI2_HOST,   ///< SPI host to use, SPIx_HOST (see spi_types.h).
            .gpio_cs = static_cast<gpio_num_t>(0),     ///< GPIO number of CS signal
            .gpio_cd = GPIO_NUM_NC,     ///< GPIO number of card detect signal
            .gpio_wp = GPIO_NUM_NC,     ///< GPIO number of write protect signal
            .gpio_int = GPIO_NUM_NC,    ///< GPIO number of interrupt line (input) for SDIO card.
    };

    sdmmc_host_t SDSPIHost = SDSPI_HOST_DEFAULT();
    SDSPIHost.flags = SDMMC_HOST_FLAG_SPI;
    SDSPIHost.slot = SDSPIDeviceConfig.host_id;
    SDSPIHost.max_freq_khz = SDMMC_FREQ_DEFAULT;

    sdspi_dev_handle_t out_handle;
    sdspi_host_init();
    if( sdspi_host_init_device(&SDSPIDeviceConfig, &out_handle) == ESP_OK)
        printf("ESP host init ok\n");
    else
        printf("ESP host init fail\n");

    sdmmc_card_init(&SDSPIHost, &sdCard);
    // Card has been initialized, print its properties
#if LOG_LOCAL_LEVEL > ESP_LOG_WARN
    sdmmc_card_print_info(stdout, &sdCard);
#endif
    printf("SD Card block size %d, read len %d, capacity %d\n", 
           sdCard.csd.sector_size,
           sdCard.csd.read_block_len,
           sdCard.csd.capacity);

     LittleFS_Mount(&sdCard);
    for(;;){
        vTaskDelay(100);
    }
}

Debug Logs

[17:53:28:418] [READ]512 byte reading time 50 ms␍␊
[17:53:28:466] [READ]512 byte reading time 40 ms␍␊
[17:53:28:753] [READ]512 byte reading time 40 ms␍␊
[17:53:28:785] [READ]512 byte reading time 40 ms␍␊
[17:53:28:833] [READ]512 byte reading time 40 ms␍␊
[17:53:29:025] [READ]512 byte reading time 50 ms␍␊
[17:53:29:152] [READ]512 byte reading time 40 ms␍␊
[17:53:29:360] [READ]512 byte reading time 40 ms␍␊

Changed SD card frequency to 40MHZ but no luck :(

[18:37:30:266] Name: SD␍␊ [18:37:30:266] Type: SDHC/SDXC␍␊ [18:37:30:266] Speed: 40 MHz␍␊ [18:37:30:266] Size: 14922MB␍␊ [18:37:30:266] CSD: ver=2, sector_size=512, capacity=30560256 read_bl_len=9␍␊ [18:37:30:266] SSR: bus_width=1␍␊ [18:37:30:266] SD Card block size 512, read len 9, capacity 30560256␍␊ [18:37:30:282] [READ]512 byte reading in 40 ms␍␊ [18:37:30:330] [READ]512 byte reading in 50 ms␍␊ [18:37:30:378] [READ]512 byte reading in 40 ms␍␊ [18:37:30:409] [READ]512 byte reading in 40 ms␍␊

Allocated dma buffers for sd card but no luck:( void* tmp_buf = heap_caps_malloc(512, MALLOC_CAP_DMA);

[18:48:37:310] [READ]512 byte reading in 40 ms␍␊ [18:48:37:358] dma capable␍␊ [18:48:37:358] [READ]512 byte reading in 40 ms␍␊ [18:48:37:646] dma capable␍␊

[19:00:50:925] [READ]512 byte reading in 120 ms␍␊ [19:00:50:925] V (21969) sdmmc_cmd: sending cmd slot=1 op=17 arg=44f flags=1c50 data=0x3ffb7884 blklen=512 datalen=512 timeout=1000<0x1b>[0m␍␊ [19:00:50:925] V (21979) sdspi_host: sdspi_host_start_command: slot=1, CMD17, arg=0x0000044f flags=0x5, data=0x3ffb7884, data_size=512 crc=0x15<0x1b>[0m␍␊ [19:00:50:968] V bus_lock: dev 5 acquired.␍␊ [19:00:50:968] D (21989) spi_master: device5 locked the bus<0x1b>[0m␍␊ [19:00:50:968] V (21999) spi_master: polling trans<0x1b>[0m␍␊ [19:00:50:968] V (21999) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:50:968] V (21999) spi_master: polling trans<0x1b>[0m␍␊ [19:00:50:968] V (22009) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:50:968] V (22009) spi_master: polling trans<0x1b>[0m␍␊ [19:00:50:968] V (22019) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:50:968] V (22019) spi_master: polling trans<0x1b>[0m␍␊ [19:00:50:968] V (22019) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:011] V (22029) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:011] V (22029) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:011] V (22029) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:011] V (22039) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:011] D (22039) sdspi_host: poll_busy: timeout<0x1b>[0m␍␊ [19:00:51:011] V (22049) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:011] V (22049) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:011] V (22049) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:011] V (22059) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:011] V (22059) bus_lock: dev 5 served from bg.<0x1b>[0m␍␊ [19:00:51:011] V (22069) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:054] V (22069) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:054] D (22069) spi_master: device5 release bus<0x1b>[0m␍␊ [19:00:51:054] V (22079) bus_lock: dev 5 released.<0x1b>[0m␍␊ [19:00:51:054] V (22079) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0x0000044b<0x1b>[0m␍␊ [19:00:51:054] V (22089) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0<0x1b>[0m␍␊ [19:00:51:054] [READ]512 byte reading in 120 ms␍␊ [19:00:51:054] V (22099) sdmmc_cmd: sending cmd slot=1 op=17 arg=43e flags=1c50 data=0x3ffb7884 blklen=512 datalen=512 timeout=1000<0x1b>[0m␍␊ [19:00:51:054] V (22109) sdspi_host: sdspi_host_start_command: slot=1, CMD17, arg=0x0000043e flags=0x5, data=0x3ffb7884, data_size=512 crc=0x53<0x1b>[0m␍␊ [19:00:51:097] V bus_lock: dev 5 acquired.␍␊ [19:00:51:097] D (22119) spi_master: device5 locked the bus<0x1b>[0m␍␊ [19:00:51:097] V (22129) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:097] V (22129) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:097] V (22129) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:097] V (22139) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:097] V (22139) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:097] V (22139) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:097] V (22149) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:097] V (22149) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:140] V (22159) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:140] V (22159) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:140] V (22159) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:140] V (22169) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:140] D (22169) sdspi_host: poll_busy: timeout<0x1b>[0m␍␊ [19:00:51:140] V (22179) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:140] V (22179) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:140] V (22179) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:140] V (22189) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:140] V (22189) bus_lock: dev 5 served from bg.<0x1b>[0m␍␊ [19:00:51:140] V (22189) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:183] V (22199) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:183] D (22199) spi_master: device5 release bus<0x1b>[0m␍␊ [19:00:51:183] V (22209) bus_lock: dev 5 released.<0x1b>[0m␍␊ [19:00:51:183] V (22209) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0x00000434<0x1b>[0m␍␊ [19:00:51:183] V (22219) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0<0x1b>[0m␍␊ [19:00:51:183] [READ]512 byte reading in 120 ms␍␊ [19:00:51:183] V (22229) sdmmc_cmd: sending cmd slot=1 op=17 arg=422 flags=1c50 data=0x3ffb7884 blklen=512 datalen=512 timeout=1000<0x1b>[0m␍␊ [19:00:51:183] V (22239) sdspi_host: sdspi_host_start_command: slot=1, CMD17, arg=0x00000422 flags=0x5, data=0x3ffb7884, data_size=512 crc=0x26<0x1b>[0m␍␊ [19:00:51:226] V bus_lock: dev 5 acquired.␍␊ [19:00:51:226] D (22249) spi_master: device5 locked the bus<0x1b>[0m␍␊ [19:00:51:226] V (22259) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:226] V (22259) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:226] V (22259) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:226] V (22269) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:226] V (22269) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:226] V (22269) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:226] V (22279) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:269] V (22279) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:269] V (22289) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:269] V (22289) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:269] V (22289) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:269] V (22299) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:269] D (22299) sdspi_host: poll_busy: timeout<0x1b>[0m␍␊ [19:00:51:269] V (22299) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:269] V (22309) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:269] V (22309) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:269] V (22319) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:269] V (22319) bus_lock: dev 5 served from bg.<0x1b>[0m␍␊ [19:00:51:269] V (22319) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:312] V (22329) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:312] D (22329) spi_master: device5 release bus<0x1b>[0m␍␊ [19:00:51:312] V (22339) bus_lock: dev 5 released.<0x1b>[0m␍␊ [19:00:51:312] V (22339) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0x00000416<0x1b>[0m␍␊ [19:00:51:312] V (22349) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0<0x1b>[0m␍␊ [19:00:51:312] [READ]512 byte reading in 120 ms␍␊ [19:00:51:312] V (22359) sdmmc_cmd: sending cmd slot=1 op=17 arg=408 flags=1c50 data=0x3ffb7884 blklen=512 datalen=512 timeout=1000<0x1b>[0m␍␊ [19:00:51:312] V (22369) sdspi_host: sdspi_host_start_command: slot=1, CMD17, arg=0x00000408 flags=0x5, data=0x3ffb7884, data_size=512 crc=0x4e<0x1b>[0m␍␊ [19:00:51:355] V bus_lock: dev 5 acquired.␍␊ [19:00:51:355] D (22379) spi_master: device5 locked the bus<0x1b>[0m␍␊ [19:00:51:355] V (22389) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:355] V (22389) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:355] V (22389) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:355] V (22399) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:355] V (22399) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:355] V (22399) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:355] V (22409) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:398] V (22409) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:398] V (22419) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:398] V (22419) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:398] V (22419) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:398] V (22429) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:398] D (22429) sdspi_host: poll_busy: timeout<0x1b>[0m␍␊ [19:00:51:398] V (22429) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:398] V (22439) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:398] V (22439) spi_master: polling trans<0x1b>[0m␍␊ [19:00:51:398] V (22449) spi_master: polling trans done<0x1b>[0m␍␊ [19:00:51:398] V (22449) bus_lock: dev 5 served from bg.<0x1b>[0m␍␊ [19:00:51:398] V (22

[19:31:47:979] Name: SD␍␊
[19:31:47:979] Type: SDHC/SDXC␍␊
[19:31:47:979] Speed: 40 MHz␍␊
[19:31:47:979] Size: 14922MB␍␊
[19:31:48:022] CSD: ver=2, sector_size=512, capacity=30560256 read_bl_len=9␍␊
[19:31:48:022] SSR: bus_width=1␍␊
[19:31:48:022] SD Card block size 512, read len 9, capacity 30560256␍␊
[19:31:48:022] <0x1b>[0;32mI (1293) example: SD card info:<0x1b>[0m␍␊
[19:31:48:022] <0x1b>[0;32mI (1303) example: ⇥  Bus width (log2): 0<0x1b>[0m␍␊
[19:31:48:022] <0x1b>[0;32mI (1303) example: ⇥  Freq (kHz): 40000<0x1b>[0m␍␊
[19:31:48:022] <0x1b>[0;32mI (1303) example: ⇥  DDR: 0<0x1b>[0m␍␊
[19:31:48:022] <0x1b>[0;32mI (1313) example: ⇥  CID: Date 338, MFG_ID 18, Name SD, OEM ID 13398, Rev 0, Serial 3271<0x1b>[0m␍␊
[19:31:48:022] <0x1b>[0;32mI (1323) example: ⇥  CSD: Capacity 30560256, Card Common Class 1461, CSD version 1, MMC version 0, read block len 9, sector size 512, tr speed 50000000<0x1b>[0m␍␊
[19:31:48:070] <0x1b>[0;32mI (1333) example: ⇥  CSD: Ease mem state 0, Power class 0, Revision 0, Sec feature 0<0x1b>[0m␍␊
[19:31:48:070] <0x1b>[0;32mI (1343) example: ⇥  SCR: bus width 5, erase mem state 1, reserved 0, rsvd_mnf 0, sd_spec 2<0x1b>[0m␍␊
[19:31:48:070] <0x1b>[0;32mI (1353) example: ⇥  SSR: cur_bus_width 0, discard_support 0, fule_support 0, reserved 0<0x1b>[0m␍␊

i have ported littlefs over sd card but i have to improve that read speed.

example code for anyone.

https://github.com/muratdemirtas/sqlite3-esp32-littlefs-sdcard-sdspi

in esp-idf-4.4 everything is ok.

21:02:26:874] [SQLite3]File position set ok, pos 2227200␍␊ [21:02:26:874] [SQLite3]Current offset 2227200, required amount 512␍␊ [21:02:26:939] [SQLite3]Readed 512 bytes␍␊ [21:02:26:939] esp32_Read: 3r JanStore.db 512 512 OK␍␊ [21:02:26:939] esp32_Read: 1r JanStore.db 512 2227712[2227712] ␍␊ [21:02:26:939] [SQLite3]File position set ok, pos 2227712␍␊ [21:02:26:939] [SQLite3]Current offset 2227712, required amount 512␍␊ [21:02:26:939] [SQLite3]Readed 512 bytes␍␊ [21:02:26:939] esp32_Read: 3r JanStore.db 512 512 OK␍␊ [21:02:26:939] esp32_Read: 1r JanStore.db 512 2228224[2228224] ␍␊ [21:02:26:939] [SQLite3]File position set ok, pos 2228224␍␊ [21:02:26:939] [SQLite3]Current offset 2228224, required amount 512␍␊ [21:02:26:939] [SQLite3]Readed 512 bytes␍␊ [21:02:26:939] esp32_Read: 3r JanStore.db 512 512 OK␍␊ [21:02:26:939] esp32_Read: 1r JanStore.db 512 2228736[2228736] ␍␊ [21:02:26:987] [SQLite3]File position set ok, pos 2228736␍␊ [21:02:26:987] [SQLite3]Current offset 2228736, required amount 512␍␊ [21:02:26:987] [SQLite3]Readed 512 bytes␍␊ [21:02:26:987] esp32_Read: 3r JanStore.db 512 512 OK␍␊ [21:02:26:987] esp32_Read: 1r JanStore.db 512 2229248[2229248] ␍␊ [21:02:26:987] [SQLite3]File position set ok, pos 2229248␍␊ [21:02:26:987] [SQLite3]Current offset 2229248, required amount 512␍␊ [21:02:26:987] [SQLite3]Readed 512 bytes␍␊

it was a spi ram allocation issue. The mmc driver using dma memory for communication with sd card. If your device allocates dma from spi ram then the esp first creating a memory block in spi ram( THIS IS THE ISSUE) which 2x spi communication makes communication slower. Thanks.

it was a spi ram allocation issue. The mmc driver using dma memory for communication with sd card. If your device allocates dma from spi ram then the esp first creating a memory block in spi ram( THIS IS THE ISSUE) which 2x spi communication makes communication slower. Thanks.

So how exactly you solved this issue? I assume that you somehow disabled using memory block in spi ram?

espressif / esp-idf