search

libretiny-eu / libretiny

PlatformIO development platform for IoT modules
http://docs.libretiny.eu/
MIT License
419 stars 62 forks source link

WiFi connection delay on CB3S module (BK7231N) #297

Open shadow578 opened 1 month ago

shadow578 commented 1 month ago

when using the CB3S module (which utilizes the BK7231N) with ESPHome firmware, the WiFi connection process takes a very long time. the module seems to fail to connect multiple times before finally establishing a connection. the issue occurs both after a cold boot as well as after a OTA update.

except from esphome config:

bk72xx:
  board: cb3s
  framework: 
    loglevel: DEBUG
    debug:
      - WIFI
    sdk_silent: auto

wifi:
  fast_connect: true
  ssid: !secret wifi_ssid
  password: !secret wifi_password
  ap:
    ssid: "${device_name} Fallback"
captive_portal:

Logs

note: some sensitive information has been redacted for privacy reasons.

Click to expand ``` V:BK7231N_1.0.1 REG:cpsr spsr r13 r14 SVC:000000D3 00401C1C 000033AC IRQ:000000d2 00000010 00401e0c 00803600 FIR:000000d1 00000010 00401ffc 16c01822 SYS:000000df 0040192c 00000158 ST:00000000 J 0x10000 [...] [C][wifi:048]: Setting up WiFi... [C][wifi:061]: Starting WiFi... [C][wifi:062]: Local MAC: XX:XX:XX:XX:XX:XX D [ 0.074] WIFI: Mode changing NULL -> STA D [ 0.078] WIFI: Initializing func&app D [ 0.412] WIFI: Init OK D [ 0.412] WIFI: Wakeup RF D [ 0.412] WIFI: Enabling STA D [ 0.420] WIFI: BK event 130 D [ 0.430] WIFI: WiFi sleep mode 0 [D][wifi:760]: Loaded saved fast_connect wifi settings [I][wifi:313]: WiFi Connecting to 'XXX'... D [ 0.434] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 D [ 0.442] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 I [ 0.450] WIFI: Connecting to XX:XX:XX:XX:XX:XX D [ 0.456] WIFI: Data = (nil) D [ 0.460] WIFI: Using DHCP D [ 0.464] WIFI: Starting WiFi... D [ 0.492] WIFI: Start OK wpa_supplicant_scan wpa_drv_scan wpa_send_scan_req no ht in scan scan_start_req_handler wpa_driver_scan_start_cb scan_cancel_req_handler scan_send_cancel_cfm wpa_driver_scan_cb Scan completed in 0.100000 seconds wpa_get_scan_rst:2 cipher2security 2 2 16 16 PSKC: end cipher2security 2 2 16 16 wpa_supplicant_connect Cancelling scan request wpa_driver_associate D [ 4.630] WIFI: BK event 1 found scan rst rssi -42 > -50 0 sm_auth_send:1 sm_disassoc_handler sm_disassoc_handler reason=8,vif=0 SM_DISCONNECTING status=1 sm_disassoc_handler sm_disassoc_handler reason=8,vif=0 ---------SM_CONNECT_IND_fail D [ 4.648] WIFI: BK event 6 [W][wifi_lt:296][wifievent]: Event: Disconnected ssid='' bssid=00:00:00:00:00:00 reason='Association Leave' [W][wifi:674]: WiFi Unknown connection status 0 [I][wifi:313]: WiFi Connecting to 'XXX'... D [ 4.680] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 D [ 4.682] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 I [ 4.690] WIFI: Connecting to XX:XX:XX:XX:XX:XX D [ 4.696] WIFI: Data = (nil) D [ 4.700] WIFI: Using DHCP D [ 4.704] WIFI: Starting WiFi... D [ 4.710] WIFI: BK event 6 [W][wifi_lt:296][wifievent]: Event: Disconnected ssid='' bssid=00:00:00:00:00:00 reason='Association Leave' D [ 4.726] WIFI: Start OK Cancelling scan request [W][wifi:674]: WiFi Unknown connection status 0 wpa_driver_associate D [ found scan rst rssi -42 > -50 0 sm_auth_send:1 4.738] WIFI: BK event 1 sm_auth_handler ht in assoc req sm_assoc_rsp_handler rc_init: station_id=1 format_mod=2 pre_type=0 short_gi=1 max_bw=0 rc_init: nss_max=0 mcs_max=7 r_idx_min=0 r_idx_max=3 no_samples=10 mm_set_vif_state_req_handler chan_bcn_detect_start ---------SM_CONNECT_IND_ok Not associated - Delay processing of received EAPOL frame (state=ASSOCIATING bssid=00:00:00:00:00:00 ) Cancelling scan request WPA: TK 6ea1d1da3e40885b00419f03c2c39161 new ie: 0 : 4e 69 65 6e 68 61 75 73 new ie: 1 : 82 84 8b 96 8c 12 98 24 new ie: 3 : 1 new ie: 2d : ef 11 1b ff ff ff 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 new ie: 30 : 1 0 0 f ac 4 1 0 0 f ac 4 2 0 0 f ac 2 0 f ac 8 80 0 hapd_intf_add_key CCMP add sta_mgmt_get_sta sta:1, vif:0, key:0 sta_mgmt_add_key add hw key idx:25 WPA: GTK 2a5b2886034cd18188a6bb5d5534c032 hapd_intf_add_key CCMP add is_broadcast_ether_addr sta:255, vif:0, key:2 add hw key idx:2 ctrl_port_hdl:1 me_set_ps_disable:869 0 0 0 0 1 dis set ps 1!! D [ WLAN_EVENT_CONNECTED sta 4.838] WIFI: BK ev_ip_start configurinent 8 g interface mlan (with DHCP client) [I][wifi:313]: WiFi Connecting to 'XXX'... D [ 9.748] WIFI: Disconnecting from XXX (wifiOff=0) bk_wlan_connection_loss vif:0 sta_ip_down mm_connection_loss_ind_handler sm_disconnect_process reason=40 me_set_ps_disable:869 0 0 1 0 8 me_set_ps_disable_req_handler 8!! mm_set_vif_state_req_handler mm_set_vif_state pass SM_DISCONNECT_IND mI [ 9.770] hdr_disconnect_ind reasWIFI: Connecting toon_code=40 deassoc_evt_ XXX D [ cb 9.778] WIFI: Data = 0x65694e01 D [ 9.782] WIFI: Using DHCP D [ 9.786] WIFI: Starting WiFi... D [ 9.792] WIFI: BK event 2 [W][wifi_lt:296][wifievent]: Event: Disconnected ssid='' bssid=00:00:00:00:00:00 reason='Beacon Timeout' D [ 9.808] WIFI: Disconnecting from (wifiOff=0) D [ 9.814] WIFI: Start OK wpa_sup[W][wifi:653]: Error while connecting to network. plicant_scan wpa_drv_scan wpa_send_scan_req no ht in scan scan_start_req_handler wpa_driver_sca[D][wifi:697]: Retrying with hidden networks... n_start_cb[I][wifi:313]: WiFi Connecting to 'XXX'... D [ 9.842] WIFIscan_cancel_req_handler : Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 D [ 9.852] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 I [ 9.862] WIFI: Connecting to XX:XX:XX:XX:XX:XX D [ 9.866] WIFI: Data = 0x65694e01 D [ 9.872] WIFI: Using DHCP D [ 9.876] WIFI: Starting WiFi... D [ 9.882] WIFI: Start OK wpa_supplicant_[W][wifi:669]: Connecting to WiFi network failed. Are the credentials wrong? scan wpa_supplicant_req_scan Setting scan request: 1.000000 sec scan_send_cancel_cfm wpa_driver_scan_cb Scan completed in 0.052000 seconds wpa_get_scan_rst:2 cipher2security 2 2 16 16 cipher2security 2 2 16 16 wpa_supplicant_connect Cancelling scan request wpa_driver_associate D [ found scan rst rssi -40 > -50 0 sm_auth_send:1 sm_disassoc_handler sm_disassoc_handler reason=8,vif=0 SM_DISCONNECTING status=1 sm_disassoc_handler sm_disassoc_handler reason=8,vif=0 ---------SM_CONNECT_IND_fail 9.940] WIFI: BK event 1 D [ 9.972] WIFI: BK event 6 [W][wifi_lt:296][wifievent]: Event: Disconnected ssid='' bssid=00:00:00:00:00:00 reason='Association Leave' [I][wifi:313]: WiFi Connecting to 'XXX'... D [ 14.904] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 D [ 14.906] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 I [ 14.914] WIFI: Connecting to XXX D [ 14.918] WIFI: Data = 0x65694e01 D [ 14.924] WIFI: Using DHCP D [ 14.928] WIFI: Starting WiFi... D [ 14.932] WIFI: BK event 6 [W][wifi_lt:296][wifievent]: Event: Disconnected ssid='' bssid=00:00:00:00:00:00 reason='Association Leave' D [ 14.948] WIFI: Start OK wpa_supplicant_sc[W][wifi:674]: WiFi Unknown connection status 0 an wpa_drv_scan wpa_send_scan_req no ht in scan scan_start_req_handler wpa_driver_scan_start_cb [D][wifi:697]: Retrying with hidden networks... [I][wifi:313]: WiFi Connecting to 'XXX'... D [ 14.978] WIFI: Disconnecscan_cancel_req_handler ting from (wifiOff=0) bk_wlan_connection_loss vif:0 D [ 14.988] WIFI: Disconnecting from (wifiOff=0) bk_wlan_connection_loss vif:0 I [ 14.996] WIFI: Connecting to XX:XX:XX:XX:XX:XX D [ 15.002] WIFI: Data = 0x65694e01 D [ 15.006] WIFI: Using DHCP D [ 15.010] WIFI: Starting WiFi... D [ 15.018] WIFI: Start OK wpa_supplicant_scan wpa_supplicant_req_scan Setting scan request: 1.000000 sec scan_send_cancel_cfm wpa_driver_scan_cb Scan completed in 0.102000 seconds wpa_get_scan_rst:2 cipher2security 2 2 16 16 cipher2security 2 2 16 16 wpa_supplicant_connect Cancelling scan request wpa_driver_associate found scan rst rssi -41 > -50 0 sm_auth_send:1 D [ 15.076] WIFI: BK event 1 sm_auth_handler ht in assoc req sm_assoc_rsp_handler rc_init: station_id=1 format_mod=2 pre_type=0 short_gi=1 max_bw=0 rc_init: nss_max=0 mcs_max=7 r_idx_min=0 r_idx_max=3 no_samples=10 mm_set_vif_state_req_handler chan_bcn_detect_start ---------SM_CONNECT_IND_ok Not associated - Delay processing of received EAPOL frame (state=ASSOCIATING bssid=00:00:00:00:00:00 ) Cancelling scan request WPA: TK a30b92505cf42faa97b8809ede382b83 old ie: 0 : 4e 69 65 6e 68 61 75 73 new ie: 0 : 4e 69 65 6e 68 61 75 73 old ie: 1 : 82 84 8b 96 8c 12 98 24 new ie: 1 : 82 84 8b 96 8c 12 98 24 old ie: 3 : 1 new ie: 3 : 1 old ie: 2d : ef 11 1b ff ff ff 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 new ie: 2d : ef 11 1b ff ff ff 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 old ie: 30 : 1 0 0 f ac 4 1 0 0 f ac 4 2 0 0 f ac 2 0 f ac 8 80 0 new ie: 30 : 1 0 0 f ac 4 1 0 0 f ac 4 2 0 0 f ac 2 0 f ac 8 80 0 hapd_intf_add_key CCMP add sta_mgmt_get_sta sta:1, vif:0, key:0 sta_mgmt_add_key add hw key idx:25 WPA: GTK 2a5b2886034cd18188a6bb5d5534c032 hapd_intf_add_key CCMP add is_broadcast_ether_addr sta:255, vif:0, key:2 add hw key idx:2 ctrl_port_hdl:1 me_set_ps_disable:869 0 0 0 0 1 dis set ps 1!! D WLAN_EVENT_CONNECTED st[ 15.200] WIFI:a_ip_start configuri BK event 8 ng interface mlan (with DHCP client) ip_addr: 827ba8c0 D [ 22.806] WIFI: BK event 9 [I][wifi:617]: WiFi Connected! [C][wifi:428]: Local MAC: XX:XX:XX:XX:XX:XX [C][wifi:433]: SSID: 'XXX' [C][wifi:436]: IP Address: XXX [C][wifi:439]: BSSID: XX:XX:XX:XX:XX:XX [C][wifi:441]: Hostname: 'motion-sensor' [C][wifi:443]: Signal strength: -44 dB [C][wifi:447]: Channel: 1 [C][wifi:448]: Subnet: 255.255.255.0 [C][wifi:449]: Gateway: XXX [C][wifi:450]: DNS1: XXX [C][wifi:451]: DNS2: XXX [D][wifi:626]: Disabling AP... ```