search

espressif / esp-now

A connectionless Wi-Fi communication protocol
Apache License 2.0
486 stars 91 forks source link

Enable spiram causes dhcp timeout #44

Closed sxsx2yzyz closed 1 year ago

sxsx2yzyz commented 1 year ago

Chip:[esp32-wrover-e 4MBflash] With spiram enable, calling esp_now_send() before calling esp_wifi_connect() will cause dhcp to time out on getting the ip. This is my code:

static const char *TAG = "app_main";
static void ip_event_handler(void *arg, esp_event_base_t event_base,
                             int32_t event_id, void *event_data)
{
    ESP_LOGE(TAG, "ip_event_handler %d", event_id);
    return;
}
static void wifi_event_handler(void *arg, esp_event_base_t event_base,
                               int32_t event_id, void *event_data)
{
    ESP_LOGE(TAG, "wifi_event_handler %d", event_id);
    if(event_id == WIFI_EVENT_STA_START || event_id == WIFI_EVENT_STA_DISCONNECTED){
        esp_wifi_connect();
    }
    return;
}

static void wifi_init()
{
    ESP_ERROR_CHECK(esp_netif_init());
    esp_event_loop_create_default();
    esp_netif_create_default_wifi_sta();
    esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &wifi_event_handler, NULL);
    esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &ip_event_handler, NULL);
    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK(esp_wifi_init(&cfg));
    ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA));
    ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_NONE));
    ESP_ERROR_CHECK(esp_wifi_start());

    wifi_config_t config = {0};
    strncpy((char *)config.sta.ssid, "ChinaNet-2.4G-3648", strlen("ChinaNet-2.4G-3648") + 1);
    strncpy((char *)config.sta.password, "quit8269", strlen("quit8269") + 1);
    esp_wifi_set_config(WIFI_IF_STA, &config);
}

static void espnow_send_task(void *arg)
{
    esp_err_t ret  = ESP_OK;
    char *data  = "hello";
    size_t size    = strlen(data);
    espnow_frame_head_t frame_head = {
        .retransmit_count = 1,
        .broadcast        = true,
        .channel = ESPNOW_CHANNEL_CURRENT,
    };
    for (;;) {
        ret = espnow_send(ESPNOW_TYPE_DATA, ESPNOW_ADDR_BROADCAST, data, size, &frame_head, portMAX_DELAY);
        if(ret != ESP_OK){
            ESP_LOGE(TAG, "Send error : %d", ret);
        }
        vTaskDelay(1000 / portTICK_RATE_MS);
    }
}

static esp_err_t espnow_recv_handle(uint8_t *src_addr, void *data,
                      size_t size, wifi_pkt_rx_ctrl_t *rx_ctrl)
{
    static uint32_t count = 0;
    ESP_LOGI(TAG, "espnow_recv, <%d> [" MACSTR "][%d][%d][%d]: %.*s", 
            count++, MAC2STR(src_addr), rx_ctrl->channel, rx_ctrl->rssi, size, size, (char *)data);
    return ESP_OK;
}

void app_main()
{
    esp_storage_init();
    wifi_init();
    espnow_config_t espnow_config = ESPNOW_INIT_CONFIG_DEFAULT();
    espnow_init(&espnow_config);
    espnow_set_type(ESPNOW_TYPE_DATA, 1, espnow_recv_handle);
    xTaskCreate(espnow_send_task, "uart_read_task", 4 * 1024, NULL, tskIDLE_PRIORITY + 1, NULL);
}

Lwip dhcp debug is enabled and all other menuconfig options are default . This is the output of disable spiram:

I (438) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (512) wifi:wifi driver task: 3ffb9a80, prio:23, stack:6656, core=0
I (512) system_api: Base MAC address is not set
I (512) system_api: read default base MAC address from EFUSE
I (522) wifi:wifi firmware version: 63017e0
I (522) wifi:wifi certification version: v7.0
I (522) wifi:config NVS flash: enabled
I (532) wifi:config nano formating: disabled
I (532) wifi:Init data frame dynamic rx buffer num: 32
I (532) wifi:Init management frame dynamic rx buffer num: 32
I (542) wifi:Init management short buffer num: 32
I (542) wifi:Init static tx buffer num: 32
I (552) wifi:Init static rx buffer size: 1600
I (552) wifi:Init static rx buffer num: 10
I (562) wifi:Init dynamic rx buffer num: 32
I (562) wifi_init: rx ba win: 6
I (562) wifi_init: tcpip mbox: 32
I (572) wifi_init: udp mbox: 6
I (572) wifi_init: tcp mbox: 6
I (582) wifi_init: tcp tx win: 5744
I (582) wifi_init: tcp rx win: 5744
I (582) wifi_init: tcp mss: 1440
I (592) wifi_init: WiFi IRAM OP enabled
I (592) wifi_init: WiFi RX IRAM OP enabled
I (602) wifi:Set ps type: 0

I (602) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (692) wifi:mode : sta (bc:dd:c2:cf:f0:f4)
I (692) wifi:enable tsf
E (692) app_main: wifi_event_handler 2
I (692) ESPNOW: espnow [version: 1.0] init
I (732) wifi:new:<6,2>, old:<1,0>, ap:<255,255>, sta:<6,2>, prof:2
I (732) wifi:state: init -> auth (b0)
I (752) wifi:state: auth -> assoc (0)
I (762) wifi:state: assoc -> run (10)
I (782) wifi:connected with ChinaNet-2.4G-3648, aid = 1, channel 6, 40D, bssid = d8:32:14:db:36:49
I (782) wifi:security: WPA2-PSK, phy: bgn, rssi: -56
I (792) wifi:pm start, type: 0

dhcp_start(netif=0x3ffb741c) st1
dhcp_start(): restarting DHCP configuration
dhcp_start(): starting DHCP configuration
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(d31bb883)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 500 msecs
E (832) app_main: wifi_event_handler 4
I (832) wifi:AP's beacon interval = 102400 us, DTIM period = 3
W (842) wifi:<ba-add>idx:0 (ifx:0, d8:32:14:db:36:49), tid:0, ssn:2, winSize:64
dhcp_recv(pbuf = 0x3ffb1880) from DHCP server 192.168.5.1 port 67
pbuf->len = 300
pbuf->tot_len = 300
skipping option 28 in options
searching DHCP_OPTION_MESSAGE_TYPE
DHCP_OFFER received in DHCP_STATE_SELECTING state
dhcp_handle_offer(netif=0x3ffb741c) st1
dhcp_handle_offer(): server 0x0105a8c0
dhcp_handle_offer(): offer for 0x2d05a8c0
dhcp_select(netif=0x3ffb741c) st1
dhcp_select(): dhcp state is REQUESTING
transaction id xid(d31bb883)
dhcp_select: REQUESTING
dhcp_select(): set request timeout 2000 msecs
dhcp_recv(pbuf = 0x3ffb1880) from DHCP server 192.168.5.1 port 67
pbuf->len = 300
pbuf->tot_len = 300
skipping option 28 in options
searching DHCP_OPTION_MESSAGE_TYPE
DHCP_ACK received
dhcp_check(netif=0x3ffb741c) st
dhcp_check(): dhcp state is CHECKING
dhcp_check(): set request timeout 500 msecs
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): CHECKING, ARP request timed out
dhcp_check(netif=0x3ffb741c) st
dhcp_check(): dhcp state is CHECKING
dhcp_check(): set request timeout 500 msecs
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): CHECKING, ARP request timed out
dhcp_bind(netif=0x3ffb741c) st1
dhcp_bind(): t0 renewal timer 86400 secs
dhcp_bind(): set request timeout 86400000 msecs
dhcp_bind(): t1 renewal timer 43200 secs
dhcp_bind(): set request timeout 43200000 msecs
dhcp_bind(): t2 rebind timer 75600 secs
dhcp_bind(): set request timeout 75600000 msecs
dhcp_bind(): IP: 0x2d05a8c0 SN: 0x00ffffff GW: 0x0105a8c0
dhcp_bind(): dhcp state is BOUND
I (1522) esp_netif_handlers: sta ip: 192.168.5.45, mask: 255.255.255.0, gw: 192.168.5.1
E (1532) app_main: ip_event_handler 0
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()

This is the output of enable spiram:

I (1372) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1382) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1432) wifi:wifi driver task: 3ffcb63c, prio:23, stack:6656, core=0
I (1432) system_api: Base MAC address is not set
I (1432) system_api: read default base MAC address from EFUSE
I (1442) wifi:wifi firmware version: 63017e0
I (1442) wifi:wifi certification version: v7.0
I (1442) wifi:config NVS flash: enabled
I (1452) wifi:config nano formating: disabled
I (1452) wifi:Init data frame dynamic rx buffer num: 32
I (1462) wifi:Init management frame dynamic rx buffer num: 32
I (1462) wifi:Init management short buffer num: 32
I (1472) wifi:Init static tx buffer num: 32
I (1472) wifi:Init tx cache buffer num: 32
I (1472) wifi:Init static rx buffer size: 1600
I (1482) wifi:Init static rx buffer num: 10
I (1482) wifi:Init dynamic rx buffer num: 32
I (1492) wifi_init: rx ba win: 6
I (1492) wifi_init: tcpip mbox: 32
I (1492) wifi_init: udp mbox: 6
I (1502) wifi_init: tcp mbox: 6
I (1502) wifi_init: tcp tx win: 5744
I (1502) wifi_init: tcp rx win: 5744
I (1512) wifi_init: tcp mss: 1440
I (1512) wifi_init: WiFi IRAM OP enabled
I (1522) wifi_init: WiFi RX IRAM OP enabled
I (1522) wifi:Set ps type: 0

I (1532) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1612) wifi:mode : sta (bc:dd:c2:cf:f0:f4)
I (1612) wifi:enable tsf
E (1612) app_main: wifi_event_handler 2
I (1622) ESPNOW: espnow [version: 1.0] init
I (1622) wifi:new:<6,2>, old:<1,0>, ap:<255,255>, sta:<6,2>, prof:2
I (1622) wifi:state: init -> auth (b0)
I (1642) wifi:state: auth -> assoc (0)
I (1662) wifi:state: assoc -> run (10)
I (1692) wifi:connected with ChinaNet-2.4G-3648, aid = 1, channel 6, 40D, bssid = d8:32:14:db:36:49
I (1692) wifi:security: WPA2-PSK, phy: bgn, rssi: -52
I (1692) wifi:pm start, type: 0

dhcp_start(netif=0x3ffbd47c) st1
dhcp_start(): restarting DHCP configuration
dhcp_start(): starting DHCP configuration
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 500 msecs
E (1732) app_main: wifi_event_handler 4
I (1732) wifi:AP's beacon interval = 102400 us, DTIM period = 3
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 1000 msecs
I (2332) app_main: espnow_recv, <0> [94:e6:86:48:82:74][6][-48][5]: hello
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 2000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
W (4442) wifi:<ba-add>idx:0 (ifx:0, d8:32:14:db:36:49), tid:0, ssn:2, winSize:64
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 4000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
W (6782) wifi:<ba-add>idx:1 (ifx:0, d8:32:14:db:36:49), tid:6, ssn:0, winSize:64
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 8000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (12332) app_main: espnow_recv, <1> [94:e6:86:48:82:74][6][-38][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 15000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (22332) app_main: espnow_recv, <2> [94:e6:86:48:82:74][6][-51][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 15000 msecs
I (32342) app_main: espnow_recv, <3> [94:e6:86:48:82:74][6][-44][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (42342) app_main: espnow_recv, <4> [94:e6:86:48:82:74][6][-49][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 15000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (52342) app_main: espnow_recv, <5> [94:e6:86:48:82:74][6][-47][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 15000 msecs
I (62342) app_main: espnow_recv, <6> [94:e6:86:48:82:74][6][-50][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
I (72342) app_main: espnow_recv, <7> [94:e6:86:48:82:74][6][-43][5]: hello
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_fine_tmr(): request timeout
dhcp_timeout()
dhcp_timeout(): restarting discovery
dhcp_discover()
dhcp_discover(): dhcp state is DISCOVER
transaction id xid(5a53c937)
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
dhcp_discover: deleting()ing
dhcp_discover: SELECTING
dhcp_discover(): set request timeout 15000 msecs
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
dhcp_coarse_tmr()
LJYSP commented 1 year ago

Can you reproduce the issue with spiram enable and not calling esp_now_send()?

sxsx2yzyz commented 1 year ago

Can you reproduce the issue with spiram enable and not calling esp_now_send()?

yes 


static const char *TAG = "app_main";
static void ip_event_handler(void *arg, esp_event_base_t event_base,
int32_t event_id, void *event_data)
{
ESP_LOGE(TAG, "ip_event_handler %d", event_id);
return;
}
static void wifi_event_handler(void *arg, esp_event_base_t event_base,
int32_t event_id, void *event_data)
{
ESP_LOGE(TAG, "wifi_event_handler %d", event_id);
if(event_id == WIFI_EVENT_STA_START || event_id == WIFI_EVENT_STA_DISCONNECTED){
esp_wifi_connect();
}
return;
}

static void wifi_init() { ESP_ERROR_CHECK(esp_netif_init()); esp_event_loop_create_default(); esp_netif_create_default_wifi_sta(); esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &wifi_event_handler, NULL); esp_event_handler_register(IP_EVENT, ESP_EVENT_ANY_ID, &ip_event_handler, NULL); wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT(); ESP_ERROR_CHECK(esp_wifi_init(&cfg)); ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA)); ESP_ERROR_CHECK(esp_wifi_set_ps(WIFI_PS_NONE)); ESP_ERROR_CHECK(esp_wifi_start());

wifi_config_t config = {0};
strncpy((char *)config.sta.ssid, "ChinaNet-2.4G-3648", strlen("ChinaNet-2.4G-3648") + 1);
strncpy((char *)config.sta.password, "quit8269", strlen("quit8269") + 1);
esp_wifi_set_config(WIFI_IF_STA, &config);

}

static void espnow_send_task(void arg) { esp_err_t ret = ESP_OK; char data = "hello"; size_t size = strlen(data); espnow_frame_head_t frame_head = { .retransmit_count = 1, .broadcast = true, .channel = ESPNOW_CHANNEL_CURRENT, }; for (;;) { // ret = espnow_send(ESPNOW_TYPE_DATA, ESPNOW_ADDR_BROADCAST, data, size, &frame_head, portMAX_DELAY); // if(ret != ESP_OK){ // ESP_LOGE(TAG, "Send error : %d", ret); // } vTaskDelay(1000 / portTICK_RATE_MS); } }

static esp_err_t espnow_recv_handle(uint8_t src_addr, void data, size_t size, wifi_pkt_rx_ctrl_t rx_ctrl) { static uint32_t count = 0; ESP_LOGI(TAG, "espnow_recv, <%d> [" MACSTR "][%d][%d][%d]: %.s", count++, MAC2STR(src_addr), rx_ctrl->channel, rx_ctrl->rssi, size, size, (char *)data); return ESP_OK; }

void app_main() { esp_storage_init(); wifi_init(); espnow_config_t espnow_config = ESPNOW_INIT_CONFIG_DEFAULT(); espnow_init(&espnow_config); espnow_set_type(ESPNOW_TYPE_DATA, 1, espnow_recv_handle); xTaskCreate(espnow_send_task, "uart_read_task", 4 * 1024, NULL, tskIDLE_PRIORITY + 1, NULL); }

optput:

I (1372) cpu_start: Starting scheduler on PRO CPU. I (0) cpu_start: Starting scheduler on APP CPU. I (1382) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations I (1432) wifi:wifi driver task: 3ffcb63c, prio:23, stack:6656, core=0 I (1432) system_api: Base MAC address is not set I (1432) system_api: read default base MAC address from EFUSE I (1442) wifi:wifi firmware version: 63017e0 I (1442) wifi:wifi certification version: v7.0 I (1442) wifi:config NVS flash: enabled I (1452) wifi:config nano formating: disabled I (1452) wifi:Init data frame dynamic rx buffer num: 32 I (1462) wifi:Init management frame dynamic rx buffer num: 32 I (1462) wifi:Init management short buffer num: 32 I (1472) wifi:Init static tx buffer num: 32 I (1472) wifi:Init tx cache buffer num: 32 I (1472) wifi:Init static rx buffer size: 1600 I (1482) wifi:Init static rx buffer num: 10 I (1482) wifi:Init dynamic rx buffer num: 32 I (1492) wifi_init: rx ba win: 6 I (1492) wifi_init: tcpip mbox: 32 I (1492) wifi_init: udp mbox: 6 I (1502) wifi_init: tcp mbox: 6 I (1502) wifi_init: tcp tx win: 5744 I (1502) wifi_init: tcp rx win: 5744 I (1512) wifi_init: tcp mss: 1440 I (1512) wifi_init: WiFi IRAM OP enabled I (1522) wifi_init: WiFi RX IRAM OP enabled I (1522) wifi:Set ps type: 0

I (1532) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07 I (1612) wifi:mode : sta (bc:dd:c2:cf:f0:f4) I (1612) wifi:enable tsf E (1622) app_main: wifi_event_handler 2 I (1622) ESPNOW: espnow [version: 1.0] init I (1622) wifi:new:<6,2>, old:<1,0>, ap:<255,255>, sta:<6,2>, prof:2 I (1622) wifi:state: init -> auth (b0) I (1652) wifi:state: auth -> assoc (0) I (1662) wifi:state: assoc -> run (10) I (1722) wifi:connected with ChinaNet-2.4G-3648, aid = 5, channel 6, 40D, bssid = d8:32:14:db:36:49 I (1722) wifi:security: WPA2-PSK, phy: bgn, rssi: -47 I (1732) wifi:pm start, type: 0

dhcp_start(netif=0x3ffbd47c) st1 dhcp_start(): restarting DHCP configuration dhcp_start(): starting DHCP configuration dhcp_discover() dhcp_discover(): dhcp state is DISCOVER transaction id xid(dafbce77) dhcp_discover: making request dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER) dhcp_discover: deleting()ing dhcp_discover: SELECTING W (1762) wifi:dhcp_discover(): set request timeout 500 msecs

idx:0 (ifx:0, d8:32:14:db:36:49), tid:0, ssn:2, winSize:64 dhcp_recv(pbuf = 0x3ffb2920) from DHCP server 192.168.5.1 port 67 pbuf->len = 300 pbuf->tot_len = 300 I (1772) wifi:skipping option 28 in options AP's beacon interval = 102400 us, DTIM period = 3 searching DHCP_OPTION_MESSAGE_TYPE E (1772) app_main: wifi_event_handler 4 DHCP_OFFER received in DHCP_STATE_SELECTING state dhcp_handle_offer(netif=0x3ffbd47c) st1 dhcp_handle_offer(): server 0x0105a8c0 dhcp_handle_offer(): offer for 0x2d05a8c0 dhcp_select(netif=0x3ffbd47c) st1 dhcp_select(): dhcp state is REQUESTING transaction id xid(dafbce77) dhcp_select: REQUESTING dhcp_select(): set request timeout 2000 msecs dhcp_recv(pbuf = 0x3ffb2920) from DHCP server 192.168.5.1 port 67 pbuf->len = 300 pbuf->tot_len = 300 skipping option 28 in options searching DHCP_OPTION_MESSAGE_TYPE DHCP_ACK received dhcp_check(netif=0x3ffbd47c) st dhcp_check(): dhcp state is CHECKING dhcp_check(): set request timeout 500 msecs dhcp_fine_tmr(): request timeout dhcp_timeout() dhcp_timeout(): CHECKING, ARP request timed out dhcp_check(netif=0x3ffbd47c) st dhcp_check(): dhcp state is CHECKING dhcp_check(): set request timeout 500 msecs dhcp_coarse_tmr() dhcp_fine_tmr(): request timeout dhcp_timeout() dhcp_timeout(): CHECKING, ARP request timed out dhcp_bind(netif=0x3ffbd47c) st1 dhcp_bind(): t0 renewal timer 86400 secs dhcp_bind(): set request timeout 86400000 msecs dhcp_bind(): t1 renewal timer 43200 secs dhcp_bind(): set request timeout 43200000 msecs dhcp_bind(): t2 rebind timer 75600 secs dhcp_bind(): set request timeout 75600000 msecs dhcp_bind(): IP: 0x2d05a8c0 SN: 0x00ffffff GW: 0x0105a8c0 dhcp_bind(): dhcp state is BOUND I (2452) esp_netif_handlers: sta ip: 192.168.5.45, mask: 255.255.255.0, gw: 192.168.5.1 E (2462) app_main: ip_event_handler 0 dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() dhcp_coarse_tmr() ``` Successfully obtained the ip when not calling esp_now_send()
LJYSP commented 1 year ago

Thanks for your feedback, we will analyse the issue later.

sxsx2yzyz commented 1 year ago

Thanks for your feedback, we will analyse the issue later.

Hi,has there been any progress?

LJYSP commented 1 year ago

DHCP is success when I use Chip:[esp32-wrover-e 2MBflash] and enable spiram with your code. ESP-IDF version is v4.4.1. SPIRAM setting: menuconfig -> component config -> ESP32-specific -> Support for external, SPI-connected RAM.

Do you have other setting about spiram? Or change another router to test?

This is my log:

I (27) boot: ESP-IDF v4.4.1-dirty 2nd stage bootloader
I (27) boot: compile time 14:26:59
I (27) boot: chip revision: 3
I (31) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (38) boot.esp32: SPI Speed      : 40MHz
I (42) boot.esp32: SPI Mode       : DIO
I (47) boot.esp32: SPI Flash Size : 2MB
I (51) boot: Enabling RNG early entropy source...
I (57) boot: Partition Table:
I (60) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (75) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  2 factory          factory app      00 00 00010000 00100000
I (90) boot: End of partition table
I (94) boot_comm: chip revision: 3, min. application chip revision: 0
I (101) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=188f4h (100596) map
I (146) esp_image: segment 1: paddr=0002891c vaddr=3ffb0000 size=0389ch ( 14492) load
I (152) esp_image: segment 2: paddr=0002c1c0 vaddr=40080000 size=03e58h ( 15960) load
I (159) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=7a080h (499840) map
I (342) esp_image: segment 4: paddr=000aa0a8 vaddr=40083e58 size=14598h ( 83352) load
I (376) esp_image: segment 5: paddr=000be648 vaddr=50000000 size=00010h (    16) load
I (388) boot: Loaded app from partition at offset 0x10000
I (388) boot: Disabling RNG early entropy source...
I (400) psram: This chip is ESP32-D0WD
I (402) spiram: Found 64MBit SPI RAM device
I (402) spiram: SPI RAM mode: flash 40m sram 40m
I (405) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (412) cpu_start: Pro cpu up.
I (416) cpu_start: Starting app cpu, entry point is 0x400813ec
0x400813ec: call_start_cpu1 at /home/lijingyi/esp/1-idf/hub/esp-idf-v4.4.1/components/esp_system/port/cpu_start.c:160

I (0) cpu_start: App cpu up.
I (1310) spiram: SPI SRAM memory test OK
I (1318) cpu_start: Pro cpu start user code
I (1318) cpu_start: cpu freq: 160000000
I (1318) cpu_start: Application information:
I (1321) cpu_start: Project name:     get-started
I (1327) cpu_start: App version:      v1.0-36-gbd43391-dirty
I (1333) cpu_start: Compile time:     Sep  5 2022 14:26:47
I (1339) cpu_start: ELF file SHA256:  dd0a3e1d12c24aff...
I (1345) cpu_start: ESP-IDF:          v4.4.1-dirty
I (1351) heap_init: Initializing. RAM available for dynamic allocation:
I (1358) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1364) heap_init: At 3FFB76E8 len 00028918 (162 KiB): DRAM
I (1370) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1377) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1383) heap_init: At 400983F0 len 00007C10 (31 KiB): IRAM
I (1390) spiram: Adding pool of 4095K of external SPI memory to heap allocator
I (1399) spi_flash: detected chip: generic
I (1402) spi_flash: flash io: dio
W (1406) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (1421) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1430) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1490) wifi:wifi driver task: 3ffc8784, prio:23, stack:6656, core=0
I (1490) system_api: Base MAC address is not set
I (1490) system_api: read default base MAC address from EFUSE
I (1510) wifi:wifi firmware version: 63017e0
I (1510) wifi:wifi certification version: v7.0
I (1510) wifi:config NVS flash: enabled
I (1510) wifi:config nano formating: disabled
I (1510) wifi:Init data frame dynamic rx buffer num: 32
I (1520) wifi:Init management frame dynamic rx buffer num: 32
I (1520) wifi:Init management short buffer num: 32
I (1530) wifi:Init static tx buffer num: 16
I (1530) wifi:Init tx cache buffer num: 32
I (1540) wifi:Init static rx buffer size: 1600
I (1540) wifi:Init static rx buffer num: 10
I (1540) wifi:Init dynamic rx buffer num: 32
I (1550) wifi_init: rx ba win: 6
I (1550) wifi_init: tcpip mbox: 32
I (1560) wifi_init: udp mbox: 6
I (1560) wifi_init: tcp mbox: 6
I (1560) wifi_init: tcp tx win: 5744
I (1570) wifi_init: tcp rx win: 5744
I (1570) wifi_init: tcp mss: 1440
I (1580) wifi_init: WiFi IRAM OP enabled
I (1580) wifi_init: WiFi RX IRAM OP enabled
I (1590) wifi:Set ps type: 0

I (1590) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (1700) wifi:mode : sta (c4:dd:57:7e:16:00)
I (1700) wifi:enable tsf
E (1710) app_main: wifi_event_handler 2
I (1710) ESPNOW: espnow [version: 1.0] init
I (1720) wifi:new:<1,1>, old:<1,0>, ap:<255,255>, sta:<1,1>, prof:1
I (1730) wifi:state: init -> auth (b0)
I (1730) wifi:state: auth -> assoc (0)
I (1740) wifi:state: assoc -> run (10)
I (1740) wifi:connected with ljyssid, aid = 3, channel 1, 40U, bssid = 70:af:6a:02:3c:22
I (1740) wifi:security: Open Auth, phy: bgn, rssi: -24
I (1750) wifi:pm start, type: 0

E (1750) app_main: wifi_event_handler 4
W (1760) wifi:<ba-add>idx:0 (ifx:0, 70:af:6a:02:3c:22), tid:0, ssn:0, winSize:64
I (1830) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (1900) app_main: espnow_recv, <0> [24:0a:c4:d6:d3:00][1][-35][5]: hello
I (2900) app_main: espnow_recv, <1> [24:0a:c4:d6:d3:00][1][-35][5]: hello
I (2980) esp_netif_handlers: sta ip: 192.168.0.32, mask: 255.255.255.0, gw: 192.168.0.1
E (2980) app_main: ip_event_handler 0
I (3900) app_main: espnow_recv, <2> [24:0a:c4:d6:d3:00][1][-36][5]: hello
I (4900) app_main: espnow_recv, <3> [24:0a:c4:d6:d3:00][1][-50][5]: hello
LJYSP commented 1 year ago

when the router is set open security, dhcp is OK. when the router is set security, we reproduce the connection is not success. We will work on the issue and feedback later.

sxsx2yzyz commented 1 year ago

when the router is set open security, dhcp is OK. when the router is set security, we reproduce the connection is not success. We will work on the issue and feedback later.

Ok,thank you

LJYSP commented 1 year ago

What's your Router Model ? It seems the issue is related to router model, I test anothor router and connection & dhcp is ok

sxsx2yzyz commented 1 year ago

Tenda AC1200 2.4G+5G

sxsx2yzyz commented 1 year ago

901662369368_ pic The router's LAN ip is 192.168.5.1

sxsx2yzyz commented 1 year ago

I just tried using mobile hotspot and found that no matter what the security setting is, connect and dhcp is ok.

zhangyanjiaoesp commented 1 year ago

@sxsx2yzyz Is your router Tenda AC11? I see AC7/AC10/AC11 all support AC1200

sxsx2yzyz commented 1 year ago

911662513203_ pic @zhangyanjiaoesp I'm not sure, but it only has ac1200 marked on it

zhangyanjiaoesp commented 1 year ago

ok, I will try to use the same router to reproduce this issue. By the way, can you provide any sniffer packets?

sxsx2yzyz commented 1 year ago

@zhangyanjiaoesp Sorry,i don't know what sniffer packets are

sxsx2yzyz commented 1 year ago

@zhangyanjiaoesp How do I get it？

zhangyanjiaoesp commented 1 year ago

you can use Ominipeek or Wireshark to capture the wifi packets.

sxsx2yzyz commented 1 year ago

@zhangyanjiaoesp What information do I need to pay attention to?

zhangyanjiaoesp commented 1 year ago

Can you reproduce the problem if the AP set to open ? If yes, you can just capture the packets from test beginning. If not, you need to set the Wireshark as this , and then start capture the packets from the test beginning.

zhangyanjiaoesp commented 1 year ago

I have reproduced your issue using a new Tenda router, will find the root cause ASAP.

sxsx2yzyz commented 1 year ago

I have reproduced your issue using a new Tenda router, will find the root cause ASAP.

OK thanks

sxsx2yzyz commented 1 year ago

I have reproduced your issue using a new Tenda router, will find the root cause ASAP.

Hi,has there been any progress?

zhangyanjiaoesp commented 1 year ago

Sorry there are other things blocked this issue, we will raise the priority to deal with this issue

sxsx2yzyz commented 1 year ago

Sorry there are other things blocked this issue, we will raise the priority to deal with this issue

OK

zhangyanjiaoesp commented 1 year ago

@sxsx2yzyz We have found the root cause, and will merge the bug fix ASAP. The fix will be backported to v4.4 also.

sxsx2yzyz commented 1 year ago

COOL!!! thank you

zhangyanjiaoesp commented 1 year ago

@sxsx2yzyz This fix has been merged into master branch 3b7d9faf78053ffc9ef0a6f518caac4050c18610, backport for v4.4 still need time.

LJYSP commented 1 year ago

@sxsx2yzyz This fix has been merged into release/v4.4， please use the release/v4.4 instead of IDF v4.4.1. Checkout the branch by: git clone -b release/v4.4 --recursive https://github.com/espressif/esp-idf.git

Or wait for the next release version v4.4.x including the fix.

sxsx2yzyz commented 1 year ago

@sxsx2yzyz This fix has been merged into release/v4.4， please use the release/v4.4 instead of IDF v4.4.1. Checkout the branch by: git clone -b release/v4.4 --recursive https://gitlab.espressif.cn:6688/espressif/esp-idf.git

Or wait for the next release version v4.4.x including the fix.

ok thank you