Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Switching SDIO speeds in feature branch #367

Open
claydonkey opened this issue Apr 16, 2024 · 12 comments
Open

Switching SDIO speeds in feature branch #367

claydonkey opened this issue Apr 16, 2024 · 12 comments

Comments

@claydonkey
Copy link

First off. Long time no see.
I would like to propose a pull request of my stm32h7 host code. It is pretty complete except for the SDIOIT part and the topic of this issue.
I don't think I have things set up properly to transfer to high speed sdio after the initial negotiation with the esp32 slave. the stm32 host codebase is now updated to the currnet esp_as_mcu_host but the command look a bit stale on my front, in telling the slave to switch to a faster clock speed:

/**
**
* @brief Initialize GPSIO in SDMMC AF
*        Please check SDMMC_reg.h for pin definitions
*
* @param  None
* @retval None
*/
void sdio_gpio_init(void)
{

    HAL_SD_MspInit(hsd1);
}
int sdio_card_init(void *ctx)
{
    log_sdio_clock_settings();
    INIT_SDIO_DEBUG();
    uint8_t bus_width;
    SDMMC_CmdInitTypeDef cmd;
    HAL_StatusTypeDef errorstate;
    g_h.funcs->_h_evt_grp_setbits(wait_trans_evt_grp, SDIO_DATA_FREE_BIT);
    uint32_t sdmmc_clk = HAL_RCCEx_GetPeriphCLKFreq(RCC_PERIPHCLK_SDMMC);
 
    __HAL_RCC_SDMMC1_CLK_ENABLE();
    SD_InitTypeDef sdmmc_init = {
        .ClockEdge = SDMMC_CLOCK_EDGE_RISING,
        .ClockPowerSave = SDMMC_CLOCK_POWER_SAVE_DISABLE,
        .BusWide = SDMMC_BUS_WIDE_1B,
        .HardwareFlowControl = SDMMC_HARDWARE_FLOW_CONTROL_DISABLE,
        .ClockDiv = sdmmc_clk / (2U * SD_INIT_FREQ)};

    sdio_trans_ready_mutex = g_h.funcs->_h_create_semaphore(10);
    SDMMC_Init(hsd1->Instance, sdmmc_init);
    hsd1->Instance->DCTRL |= SDMMC_DCTRL_SDIOEN;
    hsd1->Instance->POWER |= SDMMC_POWER_PWRCTRL;

    /* wait 74 Cycles: required power up waiting time before starting
     the SD initialization sequence */

    HAL_Delay(1U + (74U * 1000U / (sdmmc_clk / (2U * sdmmc_init.ClockDiv))));

    /* Enable SDMMC */

    /* EXTI interrupt init*/
    //  HAL_NVIC_SetPriority(EXTI9_5_IRQn, 5, 0);
    // HAL_NVIC_EnableIRQ(EXTI9_5_IRQn);
    //   __SDMMC_ENABLE_IT(hsd1->Instance, SDMMC_IT_SDIOIT);
    __SDMMC_OPERATION_ENABLE(hsd1->Instance);
    HAL_Delay(1U + (74U * 1000U / (sdmmc_clk / (2U * sdmmc_init.ClockDiv))));
    /* Command 0 - SD reset */

    cmd.Argument = 0U;
    cmd.CmdIndex = SDMMC_CMD_GO_IDLE_STATE;
    cmd.Response = SDMMC_RESPONSE_NO;
    cmd.WaitForInterrupt = SDMMC_WAIT_NO;

    cmd.CPSM = SDMMC_CPSM_ENABLE;
    SDMMC_SendCommandWait(&cmd);
    /* Command 5 - IO_SEND_OP_COND */
    cmd.Argument = 0U;
    cmd.CmdIndex = SDMMC_CMD_SDMMC_SEN_OP_COND;
    SDMMC_SendCommandWait(&cmd);

    /* Command 5 - Set VDD Voltage Window: 3.2~3.4V */
    cmd.Argument = 0x00FF8000;
    SDMMC_SendCommandWait(&cmd);

    /* Command 3 - Get WiFi address (CMD3: SEND_RELATIVE_ADDR,
     * Ask the card to publish a new relative address (RCA)) */
    cmd.Argument = 0;
    cmd.CmdIndex = SDMMC_CMD_SET_REL_ADDR;
    cmd.Response = SDMMC_RESPONSE_SHORT;
    SDMMC_SendCommandWait(&cmd);

    hsd1->SdCard.RelCardAdd = SDMMC_GetResponse(hsd1->Instance, SDMMC_RESP1);
    /* Command 7 - Select WiFi (SELECT/DESELECT_CARD) */

    cmd.Argument = 0;
    cmd.CmdIndex = SDMMC_CMD_SET_BLOCKLEN;
    SDMMC_SendCommandWait(&cmd);
    hsd1->SdCard.BlockSize = SDMMC_GetResponse(hsd1->Instance, SDMMC_RESP1);

    /* Above sequence is needed while communicating to IO only device.
     * In case of failure/timeouts despite of maximum retry, IO would be unusable
     */

    ESP_LOGI(TAG, "RCA: %lu", hsd1->SdCard.RelCardAdd);

    cmd.Argument = hsd1->SdCard.RelCardAdd;
    cmd.CmdIndex = SDMMC_CMD_SEL_DESEL_CARD;
    SDMMC_SendCommandWait(&cmd);

    uint8_t card_cap = 0;

    sdio_io_read_byte(hsd1, SDIO_FUNC_0, SD_IO_CCCR_CARD_CAP, &card_cap);
    if (!(card_cap & CCCR_CARD_CAP_LSC) || (card_cap & CCCR_CARD_CAP_4BLS))
    {
        bus_width = CCCR_BUS_WIDTH_4;
    }

    sdio_io_read_byte(hsd1, SDIO_FUNC_0, SD_IO_CCCR_BUS_WIDTH, &bus_width);
    ESP_LOGI(TAG, "Bus Width 0x%02x. sdmmc_clk: %d ClockDiv %d", bus_width, sdmmc_clk, sdmmc_init.ClockDiv);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, SD_IO_CCCR_BUS_WIDTH, CCCR_BUS_WIDTH_4, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x02, 0x02, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x10, 0x00, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x11, 0x02, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x110, 0x00, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x111, 0x02, NULL);
 
    sdmmc_init.BusWide = SDMMC_BUS_WIDE_4B;
    sdmmc_init.HardwareFlowControl = SDMMC_HARDWARE_FLOW_CONTROL_DISABLE;
   sdmmc_init.ClockDiv = 0;
    errorstate = SDMMC_Init(hsd1->Instance, sdmmc_init);
    hsd1->Instance->DCTRL |= SDMMC_DCTRL_SDIOEN;
    if (errorstate)
        return ESP_FAIL;

    sdio_io_read_byte(hsd1, SDIO_FUNC_0, SD_IO_CCCR_BUS_WIDTH, &bus_width);
    ESP_LOGI(TAG, "Bus Width 0x%02x. sdmmc_clk: %d ClockDiv %d", bus_width, sdmmc_clk, sdmmc_init.ClockDiv);
    hsd1->State = HAL_SD_STATE_READY;

   //  output CIS info from the slave
     if (hosted_sdio_print_cis_information(hsd1) != ESP_OK)
      {
         ESP_LOGW(TAG, "failed to print card info");
       }

   
    // initialise the card functions
    if (hosted_sdio_card_fn_init(hsd1) != ESP_OK)
    {
        ESP_LOGE(TAG, "hosted_sdio_init failed");
        return ESP_FAIL;
    }

    return ESP_OK;
}

the part in question is either

    sdio_io_write_byte(hsd1, SDIO_FUNC_0, SD_IO_CCCR_BUS_WIDTH, CCCR_BUS_WIDTH_4, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x02, 0x02, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x10, 0x00, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x11, 0x02, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x110, 0x00, NULL);
    sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x111, 0x02, NULL);
 
    sdmmc_init.BusWide = SDMMC_BUS_WIDE_4B;
    sdmmc_init.HardwareFlowControl = SDMMC_HARDWARE_FLOW_CONTROL_DISABLE;
   sdmmc_init.ClockDiv = 0; << strange behaviour as I can't seem to get communication at any other clockspeed

or (and my memory is hazy on this)

 if (hosted_sdio_card_fn_init(hsd1) != ESP_OK)

where do we tell the slave to change speed?

I hope everything is good with you and I hope to commence my project successfully as from when we last chatted.

@mantriyogesh
Copy link
Collaborator

mantriyogesh commented Apr 17, 2024

Hello @claydonkey ,

Good to see you back.. Hope you had great holidays.

Points to cover:

  • Write bytes code snippet
  • Slave to use 'High speed SDIO'

Write bytes code snippet

The code in discussion came into question probably because,
code in master branch refers to:

STM32WriteReg(SDIO_FUNC_0, SD_IO_CCCR_BUS_WIDTH, 0x02);
STM32WriteReg(SDIO_FUNC_0, 0x02, 0x02);
STM32WriteReg(SDIO_FUNC_0, 0x10, 0x00);
STM32WriteReg(SDIO_FUNC_0, 0x11, 0x02);
STM32WriteReg(SDIO_FUNC_0, 0x110, 0x00);
STM32WriteReg(SDIO_FUNC_0, 0x111, 0x02);

which seems stale. Using function0 is not correct in some argument. e.g.

sdio_io_write_byte(hsd1, SDIO_FUNC_0, 0x110, 0x00, NULL);

as it is func1
Please refer to the

// set FN0 block size to 512
bs = 512;
ESP_ERROR_CHECK(hosted_sdio_set_blocksize(SDIO_FUNC_0, bs));
// set FN1 block size to 512
bs = 512;
ESP_ERROR_CHECK(hosted_sdio_set_blocksize(SDIO_FUNC_1, bs));

Also, please note that func0 is not really used in ESP-Hosted.

Edit1:
Small reference document for SDIO init sequence: As per the document, ESP SDIO Slave Initialization,

@mantriyogesh
Copy link
Collaborator

Slave to use 'High speed SDIO'

Actually, the default speed at slave is by default to be 'High speed' if you use latest idf stable releases for slave building.
As part of the two steps frequency, SDIO probe/initialization/detection would be done at <=400KHz frequency.
Once CIS is populated, host can directly jump to the slave capability, I assume (@SohKamYung-Espressif will add comment further on this).

By default, slave would expose high speed capability:

choice
prompt "SDIO Bus Speed"
default ESP_SDIO_HIGH_SPEED
help
Select the SDIO Slave Bus Speed. Actual speed in use depends on SDIO bus speed the SDIO Master can support
config ESP_SDIO_DEFAULT_SPEED
bool "Default Speed (20 MHz)"
config ESP_SDIO_HIGH_SPEED
bool "High Speed (40 MHz)"
endchoice

Although, you want to mandate slave you can add

CONFIG_ESP_SDIO_HIGH_SPEED=y

in https://github.com/espressif/esp-hosted/blob/feature/esp_as_mcu_host/slave/sdkconfig.defaults.esp32

then

$ rm -rf sdkconfig build
$ idf.py set-target esp32
$ idf.py flash menuconfig

The sdkconfig file would show

CONFIG_ESP_SDIO_HIGH_SPEED=y

and ESP_SDIO_DEFAULT_SPEED would be commented

@SohKamYung-Espressif
Copy link
Contributor

@claydonkey This is from the SDIO Simplified Spec. You have to set the EHS (Enable High Speed) bit in the slave, and then switch the host to high speed.

image

@claydonkey
Copy link
Author

claydonkey commented Apr 17, 2024

Thanks guys. So it was actually running at full speed. I just wasn't sure. That pesky problem with the SDIOT is still present so I am continuous polling interrupts but would I be correct in saying that shouldn't affect the transmission speed? I have a fully fledged app using lwip an sending protoc packets over UDP. The bandwidth is quite a bit slower than I would hope at 4Mbits/sec. All I can think of as a problem is that the physical connection is not good enough (the stm32 is running at a max of 32Mhz before failing at higher speeds

@mantriyogesh
Copy link
Collaborator

mantriyogesh commented Apr 18, 2024

Hello @claydonkey ,

Software part

Polling

I think polling is still fine, but the speed you get is low, not sure if you have logic analyser to measure the actual clock released from host.

Also, the throughout depends upon polling interval. Polling could be optimised when there is already write ongoing from host.

Throughout

Have you tried raw throughout test on this setup (both tx and rx individually)?

I remember you had got a better throughout in earlier issue raised, was that and this setup different?

protoc

I have a fully fledged app using lwip an sending protoc packets over UDP

Can you please confirm, are you performing protoc encode-decode for data packets?
It would be high overhead and not needed as such. The data packets are already serialised, so you can just send the packet as is using ESP_STA_IF.
only control packets need protoc encode-decode.

Hardware part

Is the setup connected with jumper cables?
I hope that you already have the appropriate pull-ups enabled for expected sdio lines.

To mitigate polling issue, you can also just new external interrupt using any unused GPIO. In this case, slave would trigger the interrupt, when it has some data to send and clear. This interrupt now host is sure of incoming data and can start the sdio read sdio (better to read interrupt when write is not ongoing)

@mantriyogesh
Copy link
Collaborator

May we know, which feature/esp_as_mcu, you are using as reference?

Also can you please send the host and ESP log (just to double confirm if any obvious incompatibility of codes)

@claydonkey
Copy link
Author

claydonkey commented Apr 18, 2024

Hello @mantriyogesh

Have you tried raw throughout test on this setup (both tx and rx individually)?

I hate to be a bore but I have forgotten how to do this...

I remember you had got a better throughout in earlier issue raised, was that and this setup different?

All this comments below are not useful now as I have got iperf reinstated and I am getting nice rx at 20Mbits/sec in the new branch. So the problem could well be overhead in the main program...

I think it may be a case of refactoring, I havent changed anything fundamentally but it is upto the latest commit in features branch so it has inherited all the changes from m7dc00559a1d7991f06e07cc3ff1ede1a9a427ff3, I ditched the iperf I was using before. I just tested the final commit using iPerf: This the log from the old version ( can get 20Mbits/s) =>
�[0;33mW ********************************************************�[0m
�[0;33mW ********************************************************�[0m
�[0;33mW ********             ESP-Hosted                 ********�[0m
�[0;33mW ********      1.4-V-2024-04-18T14:29:27         ********�[0m
�[0;33mW ********************************************************�[0m
�[0;33mW ********************************************************�[0m
�[0;33mW Mcu CLK Freq: 291Mhz�[0m
�[0;33mW Peripheral CLK Freq: 291Mhz�[0m
�[0;33mW Transport - SDIO�[0m
�[0;33mW SDIO master, SDIO CLK Freq: 48Mhz, SDIO ClockDiv: 3�[0m
�[0;32mI Starting SDIO process rx task�[0m
�[0;32mI remote_esp_wifi_init_slave�[0m
�[0;32mI Add ESP-Hosted channel IF[0]: S[0] Tx[0x9001d16d] Rx[0x900183b5]�[0m
�[0;32mI Add ESP-Hosted channel IF[1]: S[0] Tx[0x9001d0ed] Rx[0x900183b5]�[0m
�[0;32mI Attempt connection with slave: retry[0]�[0m
�[0;32mI Reset slave using GPIO[16]�[0m
�[0;32mI transport has been reset�[0m
�[0;32mI RCA: 98304�[0m
�[0;32mI Changing OLD BUS WIDTH 0x40. Old Clock Div 364 ===>�[0m
�[0;32mI          NEW BUS WIDTH 0x42. New Clock Div 3�[0m
TUPLE: DEVICE, size: 3: D9 01 FF 
TUPLE: MANFID, size: 4
  MANF: 6666, CARD: 2222
TUPLE: FUNCID, size: 2: 0C 00 
TUPLE: FUNCE, size: 4: 00 00 02 32 
TUPLE: CONFIG, size: 5: 01 01 00 02 07 
TUPLE: CFTABLE_ENTRY, size: 8
  INDX: C1, Intface: 1, Default: 1, Conf-Entry-Num: 1
  IF: 41
  FS: 30, misc: 0, mem_space: 1, irq: 1, io_space: 0, timing: 0, power: 0
  IR: 30, mask: 1,   IRQ: FF FF
  LEN: FFFF
TUPLE: END
�[0;32mI Function 0 Blocksize: 512�[0m
�[0;32mI Function 1 Blocksize: 512�[0m
�[0;32mI generate slave intr�[0m
�[0;32mI Received INIT event from ESP32 peripheral�[0m
�[0;32mI EVENT: 12�[0m
�[0;32mI EVENT: 11�[0m
�[0;32mI capabilities: 0x1�[0m
�[0;32mI Features supported are:�[0m
�[0;32mI     * WLAN�[0m
�[0;32mI EVENT: 13�[0m
�[0;32mI ESP board type is : 0�[0m
�[0;32mI Received INIT event�[0m
�[0;32mI Base transport is set-up
�[0m
�[0;32mI Received Slave ESP Init�[0m
�[0;32mI <-- RPC_Req  [0x116]�[0m
�[0;32mI  --> RPC_Resp [0x216]�[0m
�[0;32mI <-- RPC_Req  [0x139]�[0m
�[0;32mI  --> RPC_Resp [0x239]�[0m
�[0;32mI <-- RPC_Req  [0x104]�[0m
�[0;32mI  --> RPC_Resp [0x204]�[0m
�[0;32mI <-- RPC_Req  [0x118]�[0m
�[0;32mI  --> RPC_Resp [0x218]�[0m
�[0;32mI <-- RPC_Req  [0x104]�[0m
�[0;32mI  --> RPC_Resp [0x204]�[0m
�[0;32mI <-- RPC_Req  [0x129]�[0m
�[0;32mI Event [0x2] received�[0m
�[0;32mI EVT rcvd: Wi-Fi Start�[0m
�[0;32mI <-- RPC_Req  [0x101]�[0m
�[0;32mI  --> RPC_Resp [0x229]�[0m
�[0;32mI <-- RPC_Req  [0x12b]�[0m
�[0;32mI  --> RPC_Resp [0x201]�[0m
�[0;32mI esp_netif_action_start with netif0x240b9b18 from event_id=2�[0m
�[0;32mI  --> RPC_Resp [0x22b]�[0m
�[0;32mI <-- RPC_Req  [0x10e]�[0m
�[0;32mI  --> RPC_Resp [0x20e]�[0m
�[0;32mI <-- RPC_Req  [0x104]�[0m
�[0;32mI  --> RPC_Resp [0x204]�[0m
�[0;32mI <-- RPC_Req  [0x11c]�[0m
�[0;32mI  --> RPC_Resp [0x21c]�[0m
�[0;32mI esp_hosted_wifi_connect�[0m
�[0;32mI <-- RPC_Req  [0x11a]�[0m
�[0;32mI  --> RPC_Resp [0x21a]�[0m
�[0;32mI esp_netif_action_connected with netif0x240b9b18 from event_id=4�[0m
�[0;32mI starting dhcp client�[0m
�[0;32mI esp_netif action got_ip with netif0x240b9b18 from event_id=0�[0m
�[0;32mI sta ip: 192.168.1.149, mask: 255.255.255.0, gw: 192.168.1.254�[0m
�[0;32mI got_ip_handler�[0m
�[0;32mI <-- RPC_Req  [0x103]�[0m
�[0;32mI  --> RPC_Resp [0x203]�[0m
�[0;32mI local ip 192.168.1.149�[0m
�[0;32mI local gw 192.168.1.254�[0m
�[0;32mI local nm 255.255.255.0�[0m
�[0;32mI iperf_start�[0m
�[0;32mI Socket created�[0m
�[0;32mI Socket bound, port 35091�[0m

        Interval Bandwidth
   0-   3 sec       15.21 Mbits/sec
   3-   6 sec       15.51 Mbits/sec
   6-   9 sec       15.27 Mbits/sec

I have a fully fledged app using lwip an sending protoc packets over UDP

The overhead I believe is quite small. I am even using compression but when profiled, the result of 100ms for 1000 packets seems pretty trivial?!?

Is the setup connected with jumper cables? I hope that you already have the appropriate pull-ups enabled for expected sdio
the connection is a ribbon cable between 2 sdmmc sockets.

To mitigate polling issue, you can also just new external interrupt using any unused GPIO.

This seems like a good idea. It doesn't look like it's implemented in the esp slave code. Should I plonk it in myself?

W ********************************************************
W ********************************************************
W ********             ESP-Hosted                 ********
W ********************************************************
W ********************************************************
W Mcu CLK Freq: 280000000Hz
W Peripheral CLK Freq: 280000000Hz
W Transport - SDIO
D rpc_init
D rpc_slaveif_init
D Starting tx thread
D LwIP stack has been initialized
D esp-netif has been successfully initialized
D created task for loop 0x240967a8
D created event loop 0x240967a8
D esp_netif_add_to_list 0x2409e598
D esp_netif_add_to_list netif added successfully (total netifs: 1)
D check: remote, if=0x0 fn=0x9000c9fd

D call api in lwip: ret=0x0, give sem
I remote_esp_wifi_init_slave
I Add ESP-Hosted channel IF[1]: S[0] Tx[0x9002779d] Rx[0x9000ec65]
I Add ESP-Hosted channel IF[2]: S[0] Tx[0x900276ed] Rx[0x9000ec65]
I Attempt connection with slave: retry[0]
I Reset slave using GPIO[16]
I Starting SDIO process rx task
I RCA: 98304
I Bus Width 0x40. sdmmc_clk: 40000000 ClockDiv 98
I Bus Width 0x42. sdmmc_clk: 40000000 ClockDiv 0
W Mcu CLK Freq: 280000000Hz
W Peripheral CLK Freq: 40000000Hz
W Transport - SDIO
W SYSCLK Source: 3
W AHB Prescaler: 0
W APB1 Prescaler: 64
W APB2 Prescaler: 1024
W Flash Latency: 6
W Oscillator Type: 63
W HSE State: 65536
W LSE State: 0
W HSI State: 1
W LSI State: 0
W PLL State: 2
W PLL Source: 2
W PLL M: 12
W PLL N: 280
W PLL P: 2
W PLL Q: 2
W PLL1 P: 280000000
W PLL1 Q: 280000000
W PLL1 R: 280000000
W PLL2 P: 80000000
W PLL2 Q: 53333332
W PLL2 R: 40000000
W PLL3 P: 48375000
W PLL3 Q: 48375000
W PLL3 R: 48375000
W SDIO Clock Source: 65536
W SDIO Clock Frequency: 40000000 Hz
W SDMMC Clock Divider: 0
W SDMMC Peripheral Clock Frequency: 40000000 Hz
W Effective SDIO Clock Frequency: 20000000 Hz
D >0x24087148   01 03 d9 01 ff 20 04 66  66 22 22 21 02 0c 00 22  |..... .ff""!..."|
D  0x24087158   04 00 00 02 32 1a 05 01  01 00 02 07 1b 08 c1 41  |....2..........A|
D  0x24087168   30 30 ff ff ff ff ff                              |00.....|
TUPLE: DEVICE, size: 3: D9 01 FF 
TUPLE: MANFID, size: 4
  MANF: 6666, CARD: 2222
TUPLE: FUNCID, size: 2: 0C 00 
TUPLE: FUNCE, size: 4: 00 00 02 32 
TUPLE: CONFIG, size: 5: 01 01 00 02 07 
TUPLE: CFTABLE_ENTRY, size: 8
  INDX: C1, Intface: 1, Default: 1, Conf-Entry-Num: 1
  IF: 41
  FS: 30, misc: 0, mem_space: 1, irq: 1, io_space: 0, timing: 0, power: 0
  IR: 30, mask: 1,   IRQ: FF FF
  LEN: FFFF
TUPLE: END
D IOE: 0x00
D IOR: 0x02
D IOE: 0x02
D IOE: 0x02
D IOR: 0x02
D IE: 0x00
D IE: 0x03
D BUS_WIDTH: 0x42
I Function 0 Blocksize: 512
I Function 1 Blocksize: 512
I SDIO Host operating in PACKET MODE
I generate slave intr
D Intr in Read Task: 00484000
D Intr in Read Task: 00080000
D Intr in Read Task: 00080000
D Intr in Read Task: 00080000
D Intr in Read Task: 00080000
D Intr in Read Task: 00080000
D Intr in Read Task: 00080000
D Intr in Read Task: 00CC4000
I Received INIT event from ESP32 peripheral
D Init event length: 12
I EVENT: 12
I EVENT: 11
I capabilities: 0x1
I Features supported are:
I     * WLAN
I EVENT: 13
D priv test raw tp

D slave rx queue size: 40
I ESP board type is : 0
I Base transport is set-up
I Slave chip Id[12]
I Received INIT event
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Received Event [0x301]

D EVENT: ESP INIT

I Received Slave ESP Init
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408800
D Register sync sem 0x2409f0d0 for uid 1
D <-- RPC_Req  [0x116], uid 1
D Sent RPC_Req[0x116]

D Intr in Read Task: 00408000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Resp [0x216]

D  --> RPC_Resp [0x216], uid 1
D Register sync sem 0x2409f1b8 for uid 2
D <-- RPC_Req  [0x139], uid 2
D Sent RPC_Req[0x139]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x239]

D  --> RPC_Resp [0x239], uid 2
D Register sync sem 0x2409f1b8 for uid 3
D <-- RPC_Req  [0x104], uid 3
D Sent RPC_Req[0x104]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x204]

D  --> RPC_Resp [0x204], uid 3
D Register sync sem 0x2409f1b8 for uid 4
D <-- RPC_Req  [0x118], uid 4
D Sent RPC_Req[0x118]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Resp [0x218]

D  --> RPC_Resp [0x218], uid 4
D Register sync sem 0x2409f1b8 for uid 5
D <-- RPC_Req  [0x104], uid 5
D Sent RPC_Req[0x104]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Resp [0x204]

D  --> RPC_Resp [0x204], uid 5
D Register sync sem 0x2409f1b8 for uid 6
D <-- RPC_Req  [0x129], uid 6
D Sent RPC_Req[0x129]

D Intr in Read Task: 004C7000
D Intr in Read Task: 008C0000
D Received Event [0x305]

I Event [0x2] received
I EVT rcvd: Wi-Fi Start
D event 2 recvd --> event_data:0x0 event_data_size: 0
D wifi_start esp-netif:0x2409e598 event-id2
D Register sync sem 0x2409f220 for uid 7
D <-- RPC_Req  [0x101], uid 7
D Sent RPC_Req[0x101]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x229]

D  --> RPC_Resp [0x229], uid 6
D Register sync sem 0x2409f1b8 for uid 8
D <-- RPC_Req  [0x12b], uid 8
D Sent RPC_Req[0x12b]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Received Resp [0x201]

D  --> RPC_Resp [0x201], uid 7
I Mac addr: 48:e7:29:8a:0f:28
D WIFI mac address: 48 e7 29 8a f 28
D check: remote, if=0x2409e598 fn=0x9000ca19

D call api in lwip: ret=0x0, give sem
I esp_netif_action_start with netif0x2409e598 from event_id=2
D check: remote, if=0x2409e598 fn=0x9000d63d

D esp_netif_start_api 0x2409e598
D esp_netif_get_hostname esp_netif:0x2409e598
D check: local, if=0x2409e598 fn=0x9000c8b9

D esp_netif_update_default_netif_lwip 0x2409e598
D call api in lwip: ret=0x0, give sem
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x22b]

D  --> RPC_Resp [0x22b], uid 8
D Register sync sem 0x2409f1b8 for uid 9
D <-- RPC_Req  [0x10e], uid 9
D Sent RPC_Req[0x10e]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x20e]

D  --> RPC_Resp [0x20e], uid 9
D Register sync sem 0x2409f1b8 for uid 10
D <-- RPC_Req  [0x104], uid 10
D Sent RPC_Req[0x104]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x204]

D  --> RPC_Resp [0x204], uid 10
D Register sync sem 0x2409f1b8 for uid 11
D <-- RPC_Req  [0x11c], uid 11
D Sent RPC_Req[0x11c]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x21c]

D  --> RPC_Resp [0x21c], uid 11
I esp_wifi_remote_connect
D Register sync sem 0x2409f1b8 for uid 12
D <-- RPC_Req  [0x11a], uid 12
D Sent RPC_Req[0x11a]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Resp [0x21a]

D  --> RPC_Resp [0x21a], uid 12
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Event [0x308]

D event 5 recvd --> event_data:0x2409f970 event_data_size: 41
D esp_netif action disconnected with netif0x2409e598 from event_id=5
D check: remote, if=0x2409e598 fn=0x9000d1e9

D esp_netif_down_api esp_netif:0x2409e598
D esp_netif_start_ip_lost_timer esp_netif:0x2409e598
D if0x2409e598 start ip lost tmr: no need start because netif=0x2409e620 interval=120 ip=0
D check: local, if=0x2409e598 fn=0x9000c8b9

D esp_netif_update_default_netif_lwip 0x2409e598
D call api in lwip: ret=0x0, give sem
I sta disconnect, reconnect...
I esp_wifi_remote_connect
D Register sync sem 0x2409f1f0 for uid 13
D <-- RPC_Req  [0x11a], uid 13
D Sent RPC_Req[0x11a]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x21a]

D  --> RPC_Resp [0x21a], uid 13
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Event [0x308]

D event 5 recvd --> event_data:0x2409f970 event_data_size: 41
D esp_netif action disconnected with netif0x2409e598 from event_id=5
D check: remote, if=0x2409e598 fn=0x9000d1e9

D esp_netif_down_api esp_netif:0x2409e598
D esp_netif_start_ip_lost_timer esp_netif:0x2409e598
D if0x2409e598 start ip lost tmr: no need start because netif=0x2409e620 interval=120 ip=0
D check: local, if=0x2409e598 fn=0x9000c8b9

D esp_netif_update_default_netif_lwip 0x2409e598
D call api in lwip: ret=0x0, give sem
I sta disconnect, reconnect...
I esp_wifi_remote_connect
D Register sync sem 0x2409f1f0 for uid 14
D <-- RPC_Req  [0x11a], uid 14
D Sent RPC_Req[0x11a]

D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Received Resp [0x21a]

D  --> RPC_Resp [0x21a], uid 14
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Received Event [0x307]

D event 4 recvd --> event_data:0x2409f958 event_data_size: 44
I esp_netif_action_connected with netif0x2409e598 from event_id=4
D check: remote, if=0x2409e598 fn=0x9000d111

D esp_netif_up_api esp_netif:0x2409e598
D check: local, if=0x2409e598 fn=0x9000c8b9

D esp_netif_update_default_netif_lwip 0x2409e598
D call api in lwip: ret=0x0, give sem
D check: remote, if=0x2409e598 fn=0x9000cf75

D esp_netif_dhcpc_start_api esp_netif:0x2409e598
D esp_netif_start_ip_lost_timer esp_netif:0x2409e598
D if0x2409e598 start ip lost tmr: no need start because netif=0x2409e620 interval=120 ip=0
I starting dhcp client
D call api in lwip: ret=0x0, give sem
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D esp_netif_internal_dhcpc_cb lwip-netif:0x2409e620
D if0x2409e598 ip changed=1
D Got IP wifi default handler entered
I esp_netif action got_ip with netif0x2409e598 from event_id=0
I sta ip: 192.168.1.149, mask: 255.255.255.0, gw: 192.168.1.254
I got_ip_handler
W [0] switch_mode: loading mode: [1]
W exec_loop: CLIENT 
I init_server
I Socket created
I Socket bound, port 22025
D Intr in Read Task: 00408000
D Intr in Read Task: 00408000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 008C0000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00408000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 008C0000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 008C0000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Intr in Read Task: 00CC7000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 00CC7000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 008C0000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00C00000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 00CC7000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00400000
D Intr in Read Task: 008C4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 004C7000
D Intr in Read Task: 00CC4000
D Intr in Read Task: 00CC7000
D Intr in Read Task: 00CC7000
D Intr in Read Task: 004C7000

@mantriyogesh
Copy link
Collaborator

mantriyogesh commented Apr 19, 2024

Raw throughout testing (on latest branch head)

how to do raw throughout test...

#define H_TEST_RAW_TP CONFIG_ESP_RAW_THROUGHPUT_TRANSPORT
#if H_TEST_RAW_TP
#if CONFIG_ESP_RAW_THROUGHPUT_TX_TO_SLAVE
#define H_TEST_RAW_TP_DIR (ESP_TEST_RAW_TP__HOST_TO_ESP)
#elif CONFIG_ESP_RAW_THROUGHPUT_RX_FROM_SLAVE
#define H_TEST_RAW_TP_DIR (ESP_TEST_RAW_TP__ESP_TO_HOST)
#elif CONFIG_ESP_RAW_THROUGHPUT_BIDIRECTIONAL
#define H_TEST_RAW_TP_DIR (ESP_TEST_RAW_TP__BIDIRECTIONAL)
#else
#error Test Raw TP direction not defined
#endif
#else
#define H_TEST_RAW_TP_DIR (ESP_TEST_RAW_TP_NONE)
#endif

All this comments below are not useful now as I have got iperf reinstated and I am getting nice rx at 20Mbits/sec in the new branch. So the problem could well be overhead in the main program...

Noted, thank you for the update.
Have you tried the TCP iperf? What I meant, TCP has to have acknowledgement, so rx and tx are interleaved in that sense.

Further throughout optimization

Also, in general, there are good amount of throughout optimization changes went in since your last commit,
7dc0055

Once you have some backup, you can move to latest to get these throughout numbers bumped.

To get overview of features, you can check
esp_hosted_config

And esp_hosted_config_bt

External interrupt

Regarding the outbound GPIO for triggering sdio as interrupt, it should be fairly easy change.
I am not right now sure how quickly I can provide the solution, but it should be fairly simple.

  1. Interrupt addition in stm32 ioc/configuration
  2. Enable sdio driver rw lock in host:
    #define SDIO_LOCK(x) do { \
    if (x) g_h.funcs->_h_lock_mutex(sdio_bus_lock, portMAX_DELAY); \
    } while (0);
    #define SDIO_UNLOCK(x) do { \
    if (x) g_h.funcs->_h_unlock_mutex(sdio_bus_lock); \
    } while (0);
  3. ESP to trigger interrupt (I think easiest to tweak IDF sdio driver code, where existing d1 interrupt is being raised)

Can you please send me ESP side log and sdkconfig?

@mantriyogesh
Copy link
Collaborator

Any update @claydonkey ?

1 similar comment
@mantriyogesh
Copy link
Collaborator

Any update @claydonkey ?

@claydonkey
Copy link
Author

sorry @mantriyogesh. I am still here. I have suffered a bit of a setback I won't spare you the details but I am currently unable to type at any speed (my index finger suffered an accident). I have made all manner of changes and cleanup to my host code but not really addressed the issue at hand (no pun intended). Please bear with me. I really massively appreciate all your help.

@mantriyogesh
Copy link
Collaborator

Oh dear. Take care.
Can you fork your repo? I can try with some stm and sort this ahead with external GPIO on top of your code, if that helps.

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

No branches or pull requests

3 participants