弱网环境 | rssi=70左右，esp32 开始能正常连接，自动断开后，无法重连 (IDFGH-10818)

jiafeng-1 commented 11 months ago

Answers checklist.

[X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
[X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
[X] I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

V4.4.4

Operating System used.

Linux

How did you build your project?

VS Code IDE

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

None

Development Kit.

ESP32c3-mini-1

Power Supply used.

USB

What is the expected behavior?

esp断开连接后，正常应该能正常恢复。目前再网络条件不好的情况下无法正常恢复。只能重启操作才能恢复网络。

What is the actual behavior?

目前测试，将设备放到距离较远的位置，运行一段时间后就掉线。虽然一直重连，但是无法成功。掉线后移动esp32距离wifi近一些，也是无法恢复的。只有重启才可以正常恢复网络

Steps to reproduce.

重连wifi

····
case WIFI_EVENT_STA_DISCONNECTED:

        /* This is a workaround as ESP32 WiFi libs don't currently
           auto-reassociate. */
        gl_sta_connected = false;
        memset(gl_sta_ssid, 0, 32);
        memset(gl_sta_bssid, 0, 6);
        gl_sta_ssid_len = 0;

        raco_BluFi_adv();

        ESP_LOGW(TAG, "free_heap_size = %d", esp_get_free_heap_size());

        wifi_event_sta_disconnected_t *sta_disconnect_evt =(wifi_event_sta_disconnected_t *) event_data;
        ESP_LOGW(TAG, "wifi disconnect reason:%d",sta_disconnect_evt->reason);

        // raco_retry_connect_wifi();

        // xEventGroupClearBits(wifi_event_group, CONNECTED_BIT);
        break;
····
void raco_retry_connect_wifi()
{
    static uint8_t s_retry_num = 0;
    if(s_retry_num < 3)
    {
        vTaskDelay(200000/portMAX_DELAY);
        esp_err_t err = esp_wifi_connect();
        ESP_LOGI(TAG, " [%d] retry to connect to the ap!! --> connect err = %d", s_retry_num, err);
        vTaskDelay(200000/portMAX_DELAY);
        s_retry_num++;
    }
    else
    {
        ESP_LOGI(TAG, "stop wifi and retry init wifi!!!!!!!!!!!!!!!!!!");

        esp_wifi_disconnect();
        // ESP_ERROR_CHECK(esp_wifi_stop());
        // ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA));

        wifi_config_t wifi_config;
        esp_wifi_get_config(WIFI_IF_STA, &wifi_config);
        // ESP_ERROR_CHECK(esp_wifi_start());

        #if 1
        esp_wifi_set_config(WIFI_IF_STA, &wifi_config);

        ESP_LOGW(TAG, "wifi ssid = %s\n",wifi_config.sta.ssid);
        ESP_LOGW(TAG, "wifi password = %s\n",wifi_config.sta.password);

        esp_wifi_connect();

        vTaskDelay(10000/portMAX_DELAY);

        #endif
        s_retry_num = 0;

    }

    xEventGroupClearBits(wifi_event_group, CONNECTED_BIT);
}

Debug Logs.

## 正常连接日志
虽然有disconnected的情况，但是能自动恢复。

I (81240) BLUFI_EXAMPLE: Recv STA SSID Ruijie-1

D (81390) wifi:clear blacklist
D (81390) nvs: nvs_get_str_or_blob sta.ssid
D (81390) nvs: nvs_get sta.pmf_e 1
I (81400) BLUFI_EXAMPLE: Recv STA PASSWORD hello=123

I (81490) BLUFI_EXAMPLE: BLUFI requset wifi connect to AP

D (81490) wifi:Start wifi disconnect
I (81490) wifi:state: run -> init (0)
D (81490) wifi:connect status 5 -> 6
D (81500) wifi:stop beacon/connect timer, send diassoc(8)
D (81500) wifi:sta leave
I (81500) wifi:pm stop, total sleep time: 454525 us / 1097198 us

D (81510) wifi:stop CSA timer
D (81510) wifi:remove 54:16:51:b8:79:bf from rc list
I (81520) wifi:new:<8,0>, old:<8,0>, ap:<255,255>, sta:<8,0>, prof:1
D (81520) wifi:filter: set rx policy=8
D (81530) wifi:Send disconnect event, reason=8, AP number=0
D (81530) wifi:connect status 6 -> 0
D (81540) wifi:filter: set rx policy=8
D (81540) event: running post WIFI_EVENT:5 with handler 0x4206bce0 and context 0x3fca9cac on loop 0x3fca8a7c
0x4206bce0: wifi_default_action_sta_disconnected at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:101

D (81550) esp_netif_handlers: esp_netif action disconnected with netif0x3fca99a4 from event_id=5
D (81560) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x42068a34
0x42068a34: esp_netif_down_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (81560) wifi:Start wifi connect
D (81570) wifi:connect status 0 -> 0
D (81570) wifi:connect chan=0
D (81570) wifi:first chan=8
D (81580) wifi:connect status 0 -> 1
D (81580) wifi:filter: set rx policy=3
D (81580) wifi:clear scan ap list
D (81590) wifi:start scan: type=0x50f, priority=2, cb=0x420cb2b4, arg=0x0, ss_state=0x1, time=81596818, index=0
0x420cb2b4: cnx_start_handoff_cb at ??:?

D (81600) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
D (81600) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fca99a4
D (81610) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (81610) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: no need start because netif=0x3fca9a24 interval=120 ip=0
D (81630) esp_netif_lwip: check: local, if=0x3fca99a4 fn=0x420694dc
0x420694dc: esp_netif_update_default_netif_lwip at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (81630) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca99a4
D (81640) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (81640) event: running post WIFI_EVENT:5 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (81650) [Blu_Fi_TASK]: free_heap_size = 128816
W (81660) [Blu_Fi_TASK]: wifi disconnect reason:8
D (81710) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (81710) wifi:profile match: ss_state=0x7
D (81710) wifi:scan end: arg=0x0, status=0, ss_state=0x7
D (81710) wifi:find first mathched ssid, scan done
D (81710) wifi:filter: set rx policy=4
D (81720) wifi:first chan=1
D (81720) wifi:handoff_cb: status=0
D (81720) wifi:ap found, mac=54:16:51:b8:79:bf
D (81730) wifi:new_bss=0x3fc9a6e0, cur_bss=0x0, new_chan=<8,0>, cur_chan=8
D (81730) wifi:filter: set rx policy=5
I (81740) wifi:new:<8,0>, old:<8,0>, ap:<255,255>, sta:<8,0>, prof:1
D (81740) wifi:connect_op: status=0, auth=5, cipher=3 
D (81750) wifi:auth mode is not none
D (81750) wifi:connect_bss: auth=1, reconnect=0
I (81760) wifi:state: init -> auth (b0)
D (81760) wifi:start 1s AUTH timer
D (81760) wifi:clear scan ap list
D (81770) wifi:recv auth: seq=2, status=0
I (81770) wifi:state: auth -> assoc (0)
D (81770) wifi:restart connect 1s timer for assoc
D (81790) wifi:recv assoc: type=0x10
D (81790) wifi:filter: set rx policy=6
I (81790) wifi:state: assoc -> run (10)
D (81790) wifi:start 10s connect timer for 4 way handshake
I (81890) wifi:connected with Ruijie-1, aid = 1, channel 8, BW20, bssid = 54:16:51:b8:79:bf
I (81890) wifi:security: WPA2-PSK, phy: bgn, rssi: -78
D (81890) wifi:remove all except 54:16:51:b8:79:bf from rc list
D (81890) wifi:clear blacklist
D (81900) nvs: nvs_set sta.chan 1 8
D (81900) nvs: nvs_set_blob sta.apinfo 700
D (81910) wifi:filter: set rx policy=7
I (81910) wifi:pm start, type: 1

I (81910) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000
D (81920) wifi:Send sta connected event
D (81920) wifi:connect status 1 -> 5
D (81930) wifi:obss scan is disabled
D (81930) wifi:start obss scan: obss scan is stopped
I (81930) wifi:AP's beacon interval = 102400 us, DTIM period = 1
D (81940) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (81950) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (81950) wifi:update trc
D (81960) event: running post WIFI_EVENT:4 with handler 0x4206bcfa and context 0x3fca9c7c on loop 0x3fca8a7c
0x4206bcfa: wifi_default_action_sta_connected at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:81

D (81970) esp_netif_handlers: esp_netif action connected with netif0x3fca99a4 from event_id=4
D (81970) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x420689c4
0x420689c4: esp_netif_up_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1256

D (81980) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fca99a4
D (81990) esp_netif_lwip: check: local, if=0x3fca99a4 fn=0x420694dc
0x420694dc: esp_netif_update_default_netif_lwip at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (81990) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca99a4
D (82000) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (82010) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x42068454
0x42068454: esp_netif_dhcpc_start_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1049

D (82010) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3fca99a4
D (82020) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (82030) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: no need start because netif=0x3fca9a24 interval=120 ip=0
D (82040) esp_netif_lwip: starting dhcp client
D (82040) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (82050) event: running post WIFI_EVENT:4 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

D (83040) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3fca9a24
D (83040) esp_netif_lwip: if0x3fca99a4 ip changed=1
D (83040) event: running post IP_EVENT:0 with handler 0x4206ba5c and context 0x3fca9d50 on loop 0x3fca8a7c
0x4206ba5c: wifi_default_action_sta_got_ip at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:124

D (83050) wifi_init_default: Got IP wifi default handler entered
D (83050) esp_netif_handlers: esp_netif action got_ip with netif0x3fca99a4 from event_id=0
I (83060) esp_netif_handlers: sta ip: 192.168.110.147, mask: 255.255.255.0, gw: 192.168.110.1
D (83070) event: running post IP_EVENT:0 with handler 0x4200b6a8 and context 0x3fca9da4 on loop 0x3fca8a7c
0x4200b6a8: ip_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:542

I (83080) [Blu_Fi_TASK]:  send mqtt_connected_event to queue -- event 0 

I (83090) [MANAGER_TASK]:  read queue data = 0 

D (83090) MQTT_CLIENT: Core selection disabled
D (83100) event: running post MQTT_EVENTS:7 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (83110) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=7

## 失败的日志
```c
D (1253340) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=5
I (1253350) [MQTT_TASK]: MQTT_EVENT_PUBLISHED, msg_id=40352
I (1259460) wifi:bcn_timeout,ap_probe_send_start
D (1259460) event: running post WIFI_EVENT:21 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

I (1263130) TIME: periodic timer called, time since boot: 1263137718 us
W (1263130) BLUFI_GET_RSSI: ap_mac: 54:16:51:b8:79:bf | channel:8 | RSSI:-82
D (1263130) MQTT_CLIENT: mqtt_enqueue id: 54714, type=3 successful
D (1263140) OUTBOX: ENQUEUE msgid=54714, msg_type=3, len=255, size=255
I (1263150) [MQTT_TASK]: OUTBOX_SIZE = 255 
D (1263220) MQTT_CLIENT: mqtt_message_receive: first byte: 0x50
D (1263220) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (1263220) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (1263230) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (1263230) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (1263240) MQTT_CLIENT: msg_type=5, msg_id=54714
D (1263240) MQTT_CLIENT: received MQTT_MSG_TYPE_PUBREC
D (1263400) MQTT_CLIENT: mqtt_message_receive: first byte: 0x70
D (1263400) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (1263400) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (1263410) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (1263410) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (1263420) MQTT_CLIENT: msg_type=7, msg_id=54714
D (1263430) MQTT_CLIENT: received MQTT_MSG_TYPE_PUBCOMP
D (1263430) MQTT_CLIENT: pending_id=54714, pending_msg_count = 1
D (1263440) OUTBOX: DELETED msgid=54714, msg_type=3, remain size=0
D (1263440) MQTT_CLIENT: Receive MQTT_MSG_TYPE_PUBCOMP, finish QoS2 publish
D (1263450) event: running post MQTT_EVENTS:5 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1263460) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=5
I (1263470) [MQTT_TASK]: MQTT_EVENT_PUBLISHED, msg_id=54714
I (1273130) TIME: periodic timer called, time since boot: 1273137722 us
W (1273130) BLUFI_GET_RSSI: ap_mac: 54:16:51:b8:79:bf | channel:8 | RSSI:-77
D (1273130) MQTT_CLIENT: mqtt_enqueue id: 15037, type=3 successful
D (1273140) OUTBOX: ENQUEUE msgid=15037, msg_type=3, len=255, size=255
W (1273150) wifi:m f null

I (1273150) [MQTT_TASK]: OUTBOX_SIZE = 255 
I (1277420) wifi:bcn_timeout,ap_probe_send_start
W (1277420) wifi:m f probe req l=0

D (1277420) event: running post WIFI_EVENT:21 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1277920) wifi:m f probe req l=0

I (1283130) TIME: periodic timer called, time since boot: 1283137718 us
W (1283130) BLUFI_GET_RSSI: ap_mac: 54:16:51:b8:79:bf | channel:8 | RSSI:-78
D (1283130) MQTT_CLIENT: mqtt_enqueue id: 36216, type=3 successful
D (1283140) OUTBOX: ENQUEUE msgid=36216, msg_type=3, len=255, size=510
I (1283150) [MQTT_TASK]: OUTBOX_SIZE = 510 
I (1286940) wifi:bcn_timeout,ap_probe_send_start
W (1286950) wifi:m f probe req l=0

D (1286950) event: running post WIFI_EVENT:21 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1287450) wifi:m f probe req l=0

W (1287950) wifi:m f probe req l=0

W (1288450) wifi:m f probe req l=0

I (1293130) TIME: periodic timer called, time since boot: 1293137726 us
W (1293130) BLUFI_GET_RSSI: ap_mac: 54:16:51:b8:79:bf | channel:8 | RSSI:-76
W (1294480) TRANSPORT_BASE: Poll timeout or error, errno=Connection already in progress, fd=54, timeout_ms=10000
E (1294480) MQTT_CLIENT: Writing didn't complete in specified timeout: errno=119
D (1294480) event: running post MQTT_EVENTS:0 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1294490) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=0
I (1294500) [MQTT_TASK]: MQTT_EVENT_ERROR
I (1294510) [MQTT_TASK]: Last errno string (Success)
E (1294510) MQTT_CLIENT: Error to resend data 
D (1294520) MQTT_CLIENT: Reconnect after 10000 ms
D (1294520) event: running post MQTT_EVENTS:2 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1294530) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=2
I (1294540) [MQTT_TASK]: MQTT_EVENT_DISCONNECTED
I (1294550) MQTT_CLIENT: Publishing skipped: client is not connected
I (1294550) [MQTT_TASK]: OUTBOX_SIZE = 510 
I (1300150) wifi:bcn_timeout,ap_probe_send_start
W (1300150) wifi:m f probe req l=0

D (1300150) event: running post WIFI_EVENT:21 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1300650) wifi:m f probe req l=0

W (1301150) wifi:m f probe req l=0

W (1301660) wifi:m f probe req l=0

W (1302160) wifi:m f probe req l=0

I (1302660) wifi:ap_probe_send over, resett wifi status to disassoc
I (1302660) wifi:state: run -> init (c800)
D (1302660) wifi:connect status 5 -> 3
D (1302660) wifi:send diassoc for beacon timeout(200)
W (1302670) wifi:m f disassoc

D (1302670) wifi:sta leave
I (1302670) wifi:pm stop, total sleep time: 704867759 us / 1220759731 us

D (1302680) wifi:stop CSA timer
D (1302680) wifi:remove 54:16:51:b8:79:bf from rc list
I (1302680) wifi:new:<8,0>, old:<8,0>, ap:<255,255>, sta:<8,0>, prof:1
D (1302690) wifi:filter: set rx policy=8
D (1302690) wifi:Send disconnect event, reason=200, AP number=0
D (1302700) wifi:connect status 3 -> 0
D (1302700) event: running post WIFI_EVENT:5 with handler 0x4206bce0 and context 0x3fca9cac on loop 0x3fca8a7c
0x4206bce0: wifi_default_action_sta_disconnected at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:101

D (1302710) esp_netif_handlers: esp_netif action disconnected with netif0x3fca99a4 from event_id=5
D (1302720) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x42068a34
0x42068a34: esp_netif_down_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (1302730) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fca99a4
D (1302740) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3fca9a24
D (1302740) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (1302750) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: interval=120
D (1302760) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (1302760) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: already started
D (1302770) esp_netif_lwip: check: local, if=0x3fca99a4 fn=0x420694dc
0x420694dc: esp_netif_update_default_netif_lwip at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (1302780) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca99a4
D (1302780) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1302790) event: running post WIFI_EVENT:5 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1302800) [Blu_Fi_TASK]: free_heap_size = 7088
W (1302810) [Blu_Fi_TASK]: wifi disconnect reason:200
I (1303130) TIME: periodic timer called, time since boot: 1303137756 us
W (1303130) wifi:Haven't to connect to a suitable AP now!
W (1303130) BLUFI_GET_RSSI: ap_mac: 00:00:00:00:00:00 | channel:0 | RSSI:0
D (1303140) wifi:Start wifi connect
D (1303140) wifi:connect status 0 -> 0
D (1303140) wifi:connect chan=0
D (1303150) wifi:first chan=8
D (1303150) wifi:connect status 0 -> 1
D (1303150) wifi:filter: set rx policy=3
D (1303160) wifi:clear scan ap list
D (1303160) wifi:start scan: type=0x50f, priority=2, cb=0x420cb2b4, arg=0x0, ss_state=0x1, time=1303169859, index=0
0x420cb2b4: cnx_start_handoff_cb at ??:?

D (1303170) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
I (1303180) [Blu_Fi_TASK]:  [0] retry to connect to the ap!! --> connect err = 0
I (1303180) MQTT_CLIENT: Publishing skipped: client is not connected
I (1303190) [MQTT_TASK]: OUTBOX_SIZE = 510 
D (1303420) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1303420) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (1303660) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1303660) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
D (1303900) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1303900) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
D (1304140) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1304140) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
D (1304380) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1304390) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
D (1304560) MQTT_CLIENT: Reconnecting...
D (1304560) event: running post MQTT_EVENTS:7 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1304560) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=7
I (1304570) [MQTT_TASK]: Other event id:7
D (1304570) esp-tls: host:mqtt.cloud.racobit.com: strlen 22
D (1304630) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1304630) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
D (1304870) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1304870) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
D (1305110) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1305110) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
D (1305350) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1305360) wifi:perform scan: ss_state=0x9, chan<10,0>, dur<0,120>
D (1305600) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1305600) wifi:perform scan: ss_state=0x9, chan<11,0>, dur<0,120>
D (1305840) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1305840) wifi:perform scan: ss_state=0x9, chan<12,0>, dur<360,360>
D (1306080) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1306080) wifi:perform scan: ss_state=0x9, chan<13,0>, dur<360,360>
D (1306330) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1306330) wifi:perform scan: ss_state=0x9, chan<14,0>, dur<360,360>
D (1306570) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1306570) wifi:filter: set rx policy=4
D (1306570) wifi:first chan=1
D (1306570) wifi:handoff_cb: status=0
D (1306570) wifi:clear rc list
D (1306570) wifi:clear blacklist
D (1306580) wifi:Send disconnect event, reason=201
D (1306580) wifi:connect status 1 -> 3
D (1306590) wifi:disable connect timer
D (1306590) wifi:clear scan ap list
D (1306590) event: running post WIFI_EVENT:5 with handler 0x4206bce0 and context 0x3fca9cac on loop 0x3fca8a7c
0x4206bce0: wifi_default_action_sta_disconnected at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:101

D (1306600) esp_netif_handlers: esp_netif action disconnected with netif0x3fca99a4 from event_id=5
D (1306610) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x42068a34
0x42068a34: esp_netif_down_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (1306620) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fca99a4
D (1306620) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (1306630) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: already started
D (1306640) esp_netif_lwip: check: local, if=0x3fca99a4 fn=0x420694dc
0x420694dc: esp_netif_update_default_netif_lwip at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (1306650) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca99a4
D (1306650) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1306660) event: running post WIFI_EVENT:5 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1306670) [Blu_Fi_TASK]: free_heap_size = 6020
W (1306670) [Blu_Fi_TASK]: wifi disconnect reason:201
E (1311680) esp-tls: couldn't get hostname for :mqtt.cloud.racobit.com: getaddrinfo() returns 202, addrinfo=0x0
E (1311680) TRANSPORT_BASE: Failed to open a new connection: 32769
E (1311680) MQTT_CLIENT: Error transport connect
D (1311690) event: running post MQTT_EVENTS:0 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1311700) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=0
I (1311710) [MQTT_TASK]: MQTT_EVENT_ERROR
E (1311710) [MQTT_TASK]: Last error reported from esp-tls: 0x8001
E (1311720) [MQTT_TASK]: Last error captured as transport's socket errno: 0x77
I (1311730) [MQTT_TASK]: Last errno string (Connection already in progress)
D (1311730) MQTT_CLIENT: Reconnect after 10000 ms
D (1311740) event: running post MQTT_EVENTS:2 with handler 0x42007efc and context 0x3fca7758 on loop 0x3fca6e18
0x42007efc: mqtt_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/mqtt_app/raco_mqtt_app.c:149

D (1311750) [MQTT_TASK]: Event dispatched from event loop base=MQTT_EVENTS, event_id=2
I (1311760) [MQTT_TASK]: MQTT_EVENT_DISCONNECTED
I (1313130) TIME: periodic timer called, time since boot: 1313137756 us
W (1313130) wifi:Haven't to connect to a suitable AP now!
W (1313130) BLUFI_GET_RSSI: ap_mac: 00:00:00:00:00:00 | channel:0 | RSSI:0
D (1313140) wifi:Start wifi connect
D (1313140) wifi:connect status 3 -> 0
D (1313140) wifi:connect chan=0
D (1313150) wifi:first chan=8
D (1313150) wifi:connect status 0 -> 1
D (1313150) wifi:filter: set rx policy=3
D (1313160) wifi:clear scan ap list
D (1313160) wifi:start scan: type=0x50f, priority=2, cb=0x420cb2b4, arg=0x0, ss_state=0x1, time=1313169514, index=0
0x420cb2b4: cnx_start_handoff_cb at ??:?

D (1313170) wifi:perform scan: ss_state=0x9, chan<8,0>, dur<0,120>
W (1313180) wifi:m f probe req l=0

I (1313180) [Blu_Fi_TASK]:  [1] retry to connect to the ap!! --> connect err = 0
I (1313190) MQTT_CLIENT: Publishing skipped: client is not connected
I (1313190) [MQTT_TASK]: OUTBOX_SIZE = 510 
D (1313420) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1313420) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
W (1313420) wifi:m f probe req l=0

D (1313660) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1313660) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
W (1313660) wifi:m f probe req l=0

D (1313910) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1313910) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
W (1313910) wifi:m f probe req l=0

D (1314150) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1314150) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
W (1314150) wifi:m f probe req l=0

D (1314390) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1314390) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
W (1314390) wifi:m f probe req l=0

D (1314640) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1314640) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
W (1314640) wifi:m f probe req l=0

D (1314880) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1314880) wifi:perform scan: ss_state=0x9, chan<7,0>, dur<0,120>
W (1314880) wifi:m f probe req l=0

D (1315120) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1315130) wifi:perform scan: ss_state=0x9, chan<9,0>, dur<0,120>
W (1315130) wifi:m f probe req l=0

D (1315370) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1315370) wifi:perform scan: ss_state=0x9, chan<10,0>, dur<0,120>
W (1315370) wifi:m f probe req l=0

D (1315610) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1315610) wifi:perform scan: ss_state=0x9, chan<11,0>, dur<0,120>
W (1315610) wifi:m f probe req l=0

D (1315860) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1315860) wifi:perform scan: ss_state=0x9, chan<12,0>, dur<360,360>
D (1316100) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1316100) wifi:perform scan: ss_state=0x9, chan<13,0>, dur<360,360>
D (1316340) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1316340) wifi:perform scan: ss_state=0x9, chan<14,0>, dur<360,360>
D (1316580) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (1316580) wifi:filter: set rx policy=4
D (1316580) wifi:first chan=1
D (1316580) wifi:handoff_cb: status=0
D (1316580) wifi:clear rc list
D (1316590) wifi:clear blacklist
D (1316590) wifi:Send disconnect event, reason=201
D (1316600) wifi:connect status 1 -> 3
D (1316600) wifi:disable connect timer
D (1316600) wifi:clear scan ap list
D (1316610) event: running post WIFI_EVENT:5 with handler 0x4206bce0 and context 0x3fca9cac on loop 0x3fca8a7c
0x4206bce0: wifi_default_action_sta_disconnected at /home/jiafeng/esp/esp-idf/components/esp_wifi/src/wifi_default.c:101

D (1316620) esp_netif_handlers: esp_netif action disconnected with netif0x3fca99a4 from event_id=5
D (1316620) esp_netif_lwip: check: remote, if=0x3fca99a4 fn=0x42068a34
0x42068a34: esp_netif_down_api at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1279

D (1316630) esp_netif_lwip: esp_netif_down_api esp_netif:0x3fca99a4
D (1316640) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fca99a4
D (1316640) esp_netif_lwip: if0x3fca99a4 start ip lost tmr: already started
D (1316650) esp_netif_lwip: check: local, if=0x3fca99a4 fn=0x420694dc
0x420694dc: esp_netif_update_default_netif_lwip at /home/jiafeng/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:188

D (1316660) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fca99a4
D (1316670) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1316670) event: running post WIFI_EVENT:5 with handler 0x4200bb76 and context 0x3fca9d84 on loop 0x3fca8a7c
0x4200bb76: wifi_event_handler at /home/jiafeng/jiafeng/code/Bioradar/software/radar_comm_board/Bioradar_raco_comm_for_esp32/build/../components/blu_fi_app/blu_fi_app.c:587

W (1316680) [Blu_Fi_TASK]: free_heap_size = 5208
W (1316690) [Blu_Fi_TASK]: wifi disconnect reason:201



### More Information.

_No response_

Xiehanxin commented 11 months ago

hi @jiafeng-1 从Log 看没连上的原因是没有扫描到 AP （201），问一下是某个路由器有这个情况还是都有，然后如果是特定路由器的话能提供下路由器的型号吗，另外问一下你这边有抓包环境吗

jiafeng-1 commented 11 months ago

hi @jiafeng-1 从Log 看没连上的原因是没有扫描到 AP （201），问一下是某个路由器有这个情况还是都有，然后如果是特定路由器的话能提供下路由器的型号吗，另外问一下你这边有抓包环境吗

对的，是没有扫描到AP，但是重启是可以扫描到的。
应该是所有的都有，目前客户和我在公司测试都遇到了，弱网环境，上行带宽在0.7-1.2Mbps，下行带宽4.5-5.7Mbps。rssi 在-50-70的情况下断网后，不能正常恢复。
客户的网络环境是多相同的SSID网络环境。我已经手动把漫游值调成了-90，应该不至于产生漫游。公司的网络是独立的ap
目前用的Ruijie RG-EW3200GX 、TP-LINK TL-WAR6200L两个型号。
我可以尝试抓包，但是不清楚怎么抓，抓那些数据。

jiafeng-1 commented 11 months ago

[Uploading esp32_wireshark.zip…]() 这是我使用wireShark抓了一些包，不知道有没有用！

Xiehanxin commented 11 months ago

Uploading esp32_wireshark.zip… 这是我使用wireShark抓了一些包，不知道有没有用！

不好意思，我这边下载不了你的附件，打开还是这个issue的链接，另外你如果抓了包，可以提供下设备的MAC地址，路由器的账号密码信息吗

jiafeng-1 commented 11 months ago

归档.zip 您好，我这边抓取了，相关数据，可以看下，mac地址等相关信息在压缩包里。还有一个文件太大无法上传。

Uploading esp32_wireshark.zip… 这是我使用wireShark抓了一些包，不知道有没有用！

不好意思，我这边下载不了你的附件，打开还是这个issue的链接，另外你如果抓了包，可以提供下设备的MAC地址，路由器的账号密码信息吗

notcaremath commented 10 months ago

遇到了同样的问题，我在重连中加了尝试次数，超次数重启设备然后可以连接，关注后续解决

Jacques-Zhao commented 10 months ago

@jiafeng-1 你这个连不上的原因是这个打印导致的 “wifi:m f probe req l=0”，这个代表WiFi的 buffer满了，所以收发包会有异常，考虑到你们当前剩余内存还比较多，你可以尝试先把WiFi动态buffer调大一些

01hello commented 10 months ago

@jiafeng-1 您好我的情况和您的是一样的，请问有解决吗

maenkai commented 6 months ago

我也遇到了同样的情况，希望能得到解决

Hard-bitten commented 1 week ago

遇到了同样的问题，有解决方案么？

MaxwellAlan commented 1 week ago

Hi @Hard-bitten

关于这个问题，帮忙提供一下详细的复现log（如果能提供WIFI无线抓包更好）及复现步骤，以便我们进一步分析

1.测试的IDF commit 2.测试的路由器型号及配置； 3.复现的 demo code 及 sdkconfig； 4.所用的模组型号及芯片型号等信息

谢谢。

espressif / esp-idf