search

espressif / esp-hosted

Hosted Solution (Linux/MCU) with ESP32 (Wi-Fi + BT + BLE)
Other
630 stars 145 forks source link

Switching SDIO speeds in feature branch #367

Open claydonkey opened 3 months ago

claydonkey commented 3 months ago

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 commented 2 months ago

Hello @claydonkey ,

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

Points to cover:

Write bytes code snippet

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

https://github.com/espressif/esp-hosted/blob/c7dd9e1dabc33fe5a3c7f9a93b6955de194b0bfe/esp_hosted_fg/host/stm32/driver/transport/sdio/sdio_ll.c#L464-L469

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 https://github.com/espressif/esp-hosted/blob/7df1a1452364dc62d009e0e4fa911308bdb617ab/host/port/sdio_wrapper.c#L159-L165

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 commented 2 months ago

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: https://github.com/espressif/esp-hosted/blob/7df1a1452364dc62d009e0e4fa911308bdb617ab/slave/main/Kconfig.projbuild#L227-L238

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 commented 2 months ago

@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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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 commented 2 months ago

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) =>

W ********************************************************
W ********************************************************
W ********             ESP-Hosted                 ********
W ********      1.4-V-2024-04-18T14:29:27         ********
W ********************************************************
W ********************************************************
W Mcu CLK Freq: 291Mhz
W Peripheral CLK Freq: 291Mhz
W Transport - SDIO
W SDIO master, SDIO CLK Freq: 48Mhz, SDIO ClockDiv: 3
I Starting SDIO process rx task
I remote_esp_wifi_init_slave
I Add ESP-Hosted channel IF[0]: S[0] Tx[0x9001d16d] Rx[0x900183b5]
I Add ESP-Hosted channel IF[1]: S[0] Tx[0x9001d0ed] Rx[0x900183b5]
I Attempt connection with slave: retry[0]
I Reset slave using GPIO[16]
I transport has been reset
I RCA: 98304
I Changing OLD BUS WIDTH 0x40. Old Clock Div 364 ===>
I          NEW BUS WIDTH 0x42. New Clock Div 3
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
I Function 0 Blocksize: 512
I Function 1 Blocksize: 512
I generate slave intr
I Received INIT event from ESP32 peripheral
I EVENT: 12
I EVENT: 11
I capabilities: 0x1
I Features supported are:
I     * WLAN
I EVENT: 13
I ESP board type is : 0
I Received INIT event
I Base transport is set-up

I Received Slave ESP Init
I <-- RPC_Req  [0x116]
I  --> RPC_Resp [0x216]
I <-- RPC_Req  [0x139]
I  --> RPC_Resp [0x239]
I <-- RPC_Req  [0x104]
I  --> RPC_Resp [0x204]
I <-- RPC_Req  [0x118]
I  --> RPC_Resp [0x218]
I <-- RPC_Req  [0x104]
I  --> RPC_Resp [0x204]
I <-- RPC_Req  [0x129]
I Event [0x2] received
I EVT rcvd: Wi-Fi Start
I <-- RPC_Req  [0x101]
I  --> RPC_Resp [0x229]
I <-- RPC_Req  [0x12b]
I  --> RPC_Resp [0x201]
I esp_netif_action_start with netif0x240b9b18 from event_id=2
I  --> RPC_Resp [0x22b]
I <-- RPC_Req  [0x10e]
I  --> RPC_Resp [0x20e]
I <-- RPC_Req  [0x104]
I  --> RPC_Resp [0x204]
I <-- RPC_Req  [0x11c]
I  --> RPC_Resp [0x21c]
I esp_hosted_wifi_connect
I <-- RPC_Req  [0x11a]
I  --> RPC_Resp [0x21a]
I esp_netif_action_connected with netif0x240b9b18 from event_id=4
I starting dhcp client
I esp_netif action got_ip with netif0x240b9b18 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
I <-- RPC_Req  [0x103]
I  --> RPC_Resp [0x203]
I local ip 192.168.1.149
I local gw 192.168.1.254
I local nm 255.255.255.0
I iperf_start
I Socket created
I Socket bound, port 35091

        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 commented 2 months ago

Raw throughout testing (on latest branch head)

how to do raw throughout test...

https://github.com/espressif/esp-hosted/blob/7df1a1452364dc62d009e0e4fa911308bdb617ab/host/port/esp_hosted_config.h#L198-L212

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, 7dc00559a1d7991f06e07cc3ff1ede1a9a427ff3

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: https://github.com/espressif/esp-hosted/blob/7df1a1452364dc62d009e0e4fa911308bdb617ab/host/port/sdio_wrapper.c#L36-L42
  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 commented 2 months ago

Any update @claydonkey ?

mantriyogesh commented 2 months ago

Any update @claydonkey ?

claydonkey commented 2 months ago

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 commented 2 months ago

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.