一.密码为空导致连接失败:

问题现象描述:

    用户连接2个wifi后。界面上关闭wifi。过10s后再次打开wifi。选择连接wifiA,界面一直现在"正在连接中",60s后,界面"界面连接中"的显示小时。回退到主界面再次进入到wifi界面,发现显示连接的wifi是wifiB.

原因分析:

1.分析测试提供的问题视频,梳理操作步骤

        1.初始状态,wifi已连接:TP-******860        
        2.切换连接wifi:Ise************-5G,连接成功,界面上也显示到连接了 Ise************-5G
        3.界面上操作关闭wifi
        4.过了大概10s 再次打开wifi。并选择 TP-******860 进行连接。 界面一直显示"正在连接TP-..."
            大概经过60s!界面的显示框 "正在连接TP-..." 直接消失也没有任何错误提示!    
        5.回到主界面。再次进入settings的无线网络界面显示已连接的wifi是: Ise************-5G

2.日志分析

   根据上面梳理出来的操作步骤,一一对应日志分析。发现在连接TP-******860时。报了"preSharedKey is empty!"的错误,导致连接失败。随后wifi框架层又走了自动连接流程选择连接的是Ise************-5G。!
    行 138458: 01-21 10:32:14.102  3442  3442 I C01560/WifiNAPIUtils: Call wifi func: ConnectToDevice (start)
    行 138468: 01-21 10:32:14.105  3387  3583 I C01560/WifiDeviceServiceImpl: CheckConfigPwd: keyMgmt = WPA-PSK!
    行 138469: 01-21 10:32:14.105  3387  3583 E C01560/WifiDeviceServiceImpl: CheckConfigPwd: preSharedKey is empty!
    行 138470: 01-21 10:32:14.105  3387  3583 E C01560/WifiDeviceServiceImpl: CheckConfigPwd failed!
    
    行 141583: 01-21 10:32:19.814  3387  3586 I C01560/StaAutoConnectService: AutoSelectDevice networkId: 3, ssid: Ise************-5G, bssid: 50:6a:**:**:**:73.
    行 141632: 01-21 10:32:19.849  3387  3585 I C01560/StaStateMachine: SetBssid bssid=50:6a:**:**:**:73
    行 141652: 01-21 10:32:19.853  4061  4062 I C05200/wpa_supplicant:    selected BSS 50:6a:**:**:**:73 ssid='Ise************-5G'
    行 141653: 01-21 10:32:19.854  4061  4062 I C05200/wpa_supplicant: wlan0: Request association with 50:6a:**:**:**:73
    行 141714: 01-21 10:32:19.908  4061  4062 I C05200/wpa_supplicant: SME: Trying to authenticate with 50:6a:**:**:**:73 (SSID='Ise************-5G' freq=5765 MHz)
    行 141796: 01-21 10:32:19.954  4061  4062 I C05200/wpa_supplicant: wlan0: CTRL-EVENT-CONNECTED - Connection to 50:6a:**:**:**:73 completed [id=0 id_str=]

3.日志结合代码分析:

    可以看到,在连接wifi的时候,进行密码的检查。发现密码为空!故而连接失败。

       

4.应用层分析结论

    由于连接时应用层触发的动作,ssid和密码等信息都是应用侧传递的。故而需要应用层分析。应用层分析的结论是,密码传空的原因是调用接口wifiManager.getDeviceConfigs获取到的preShareKey为空字符串!

5.wifiManager.getDeviceConfigs获取的字符串为空的原因分析

1.首先梳理接口调用流程:

        

2.分析WifiSettings::GetDeviceConfig函数的逻辑

    结论:配置信息被保存在成员变量mWifiDeviceConfig中。获取即是从该成员变量中获取!

    

测试反馈该问题是概率问题,且概率较低!所以尝试在WifiSettings::GetDeviceConfig所有的重载函数中加调试日志,什么时候获取为Null什么时候获取的密码不为Null。

解决方案:

 

二.wlan0接口异常INTERFACE_DISABLED导致连接失败:

问题现象描述:

    测试连接wifi(名称为:123456)时连接失败。特意强调已界面明文检查密码没有出错!问题时间点是17:09

日志分析:

        行 12526: 02-06 17:09:22.008  5379  5379 I C01560/WifiNAPIUtils: Call wifi func: ConnectToDevice (start)
        行 12544: 02-06 17:09:22.010  3947  4498 I C01560/WifiDeviceServiceImpl: ConnectToDevice: device address <private>, addressType:0
        行 12549: 02-06 17:09:22.011  3947  4498 I C01560/WifiDeviceServiceImpl: CheckConfigPwd: keyMgmt = SAE!
        行 12550: 02-06 17:09:22.011  3947  4498 I C01560/WifiDeviceServiceImpl: CheckConfigPwd, ssid: 1***56, psk len: 8
        行 12553: 02-06 17:09:22.011  3947  4498 I C01560/WifiFrameWork: Enter Connect.
        行 12554: 02-06 17:09:22.011  3947  4498 I C01560/WifiFrameWork: Enter ConnectToDevice, ssid = 1***56 instId:0. 
        行 12555: 02-06 17:09:22.011  3947  4498 I C01560/WifiFrameWork: Enter AddDeviceConfig, ssid:1***56, bssid=82:41:**:**:**:c0, keyMgmt: SAE
        行 12623: 02-06 17:09:22.027  3947  4498 I C01560/WifiFrameWork: ConnectToDevice, netWorkId: 2
        
        行 12658: 02-06 17:09:22.033  3947  4950 I C01560/WifiFrameWork: SetUserConnectChoice enter, networkId:2, ssid: 1***56
        行 12666: 02-06 17:09:22.034  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
        行 12667: 02-06 17:09:22.034  2933  2933 E C01560/WifiHalWpaCommon: [<private>] command failed.
        行 12670: 02-06 17:09:22.034  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!

    结论:wpa_supplicant异常了!命令无法下发到wpa_supplicant去执行!

分析wpa_supplicant异常的原因:

    向前追踪日志,找到wpa_ctrl_request send fail!第一次出现的地方如下:

    行 66692: 02-06 17:06:56.682  4195  4196 I C05200/wpa_supplicant: p2p0: Event INTERFACE_DISABLED (26) received
    行 66695: 02-06 17:06:56.682  4195  4196 I C05200/wpa_supplicant: p2p0: State: DISCONNECTED -> DISCONNECTED
    行 66766: 02-06 17:06:56.722  4195  4196 I C05200/wpa_supplicant: The radio work list is empty
    行 66767: 02-06 17:06:56.723  4195  4196 I C05200/wpa_supplicant: p2p0: State: DISCONNECTED -> INTERFACE_DISABLED
    行 66779: 02-06 17:06:56.726  4195  4196 I C05200/wpa_supplicant: wlan0: Event INTERFACE_DISABLED (26) received
    行 66783: 02-06 17:06:56.726  4195  4196 I C05200/wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED bssid=82:41:**:**:**:c0 reason=3 locally_generated=1
    行 66785: 02-06 17:06:56.726  4195  4196 I C05200/wpa_supplicant: wlan0: State: COMPLETED -> DISCONNECTED
    行 66802: 02-06 17:06:56.728  4195  4196 I C05200/wpa_supplicant: The radio work list is empty
    行 66803: 02-06 17:06:56.728  4195  4196 I C05200/wpa_supplicant: wlan0: State: DISCONNECTED -> INTERFACE_DISABLED
    行 66806: 02-06 17:06:56.729  4195  4196 I C05200/wpa_supplicant: wlan0: Event INTERFACE_STATUS (5) received
    行 66807: 02-06 17:06:56.730  4195  4196 I C05200/wpa_supplicant: wlan0: State: INTERFACE_DISABLED -> INTERFACE_DISABLED
    行 66865: 02-06 17:06:56.740  4195  4196 I C05200/wpa_supplicant: p2p0: Event INTERFACE_STATUS (5) received
    行 66866: 02-06 17:06:56.740  4195  4196 I C05200/wpa_supplicant: p2p0: State: INTERFACE_DISABLED -> INTERFACE_DISABLED
    行 66868: 02-06 17:06:56.740  4195  4196 I C05200/wpa_supplicant: p2p0: Removing interface p2p0
    行 66891: 02-06 17:06:56.746  4195  4196 W C05200/wpa_supplicant: Request to deauthenticate - bssid=00:00:**:**:**:00 pending_bssid=00:00:**:**:**:00 reason=3 (DEAUTH_LEAVING) state=INTERFACE_DISABLED valid_links=0x0 ap_mld_addr=00:00:**:**:**:00
    行 66892: 02-06 17:06:56.746  4195  4196 I C05200/wpa_supplicant: p2p0: CTRL-EVENT-DSCP-POLICY clear_all
    行 66895: 02-06 17:06:56.747  4195  4196 I C05200/wpa_supplicant: Enter eapol_sm_deinit
    行 66896: 02-06 17:06:56.747  4195  4196 I C05200/wpa_supplicant: Enter eap_peer_sm_deinit
    行 66897: 02-06 17:06:56.747  4195  4196 I C05200/wpa_supplicant: Enter tls_deinit
    行 66899: 02-06 17:06:56.747  4195  4196 I C05200/wpa_supplicant: Leave tls_deinit
    行 66902: 02-06 17:06:56.748  4195  4196 I C05200/wpa_supplicant: Enter tls_deinit
    行 66904: 02-06 17:06:56.748  4195  4196 I C05200/wpa_supplicant: Leave tls_deinit
    行 66905: 02-06 17:06:56.748  4195  4196 I C05200/wpa_supplicant: Leave eap_peer_sm_deinit
    行 66906: 02-06 17:06:56.748  4195  4196 I C05200/wpa_supplicant: Leave eapol_sm_deinit
    行 66925: 02-06 17:06:56.755  4195  4196 I C05200/wpa_supplicant: p2p0: Cancelling scan request
    行 66926: 02-06 17:06:56.756  4195  4196 I C05200/wpa_supplicant: The radio work list is empty

    行 66930: 02-06 17:06:56.756  4195  4196 I C05200/wpa_supplicant: p2p0: CTRL-EVENT-DSCP-POLICY clear_all
    行 66936: 02-06 17:06:56.756  4195  4196 W C05200/wpa_supplicant: P2P: State IDLE -> IDLE
    行 66937: 02-06 17:06:56.756  4195  4196 E C05200/wpa_supplicant: wpa_driver_set_ap_wps_p2p_ie: Entry
    行 66941: 02-06 17:06:56.756  4195  4196 I C05200/wpa_supplicant: Remove interface p2p0 from radio phy0
    行 66943: 02-06 17:06:56.757  4195  4196 I C05200/wpa_supplicant: The radio work list is empty
    行 66945: 02-06 17:06:56.757  4195  4196 I C05200/wpa_supplicant: nl80211: deinit ifname=p2p0 disabled_11b_rates=0
    行 66950: 02-06 17:06:56.757  4195  4196 E C05200/wpa_supplicant: Could not read interface p2p0 flags: No such device
    行 66958: 02-06 17:06:56.758  4195  4196 E C05200/wpa_supplicant: Could not read interface p2p0 flags: No such device
    行 80923: 02-06 17:07:06.751  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 80986: 02-06 17:07:06.756  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 80989: 02-06 17:07:06.756  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 83805: 02-06 17:07:08.761  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 83808: 02-06 17:07:08.761  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 86500: 02-06 17:07:10.764  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!
    行 86503: 02-06 17:07:10.764  2933  2933 E C05200/wpa_supplicant: wpa_ctrl_request send fail!

        分析对应时间点的内核日志:
        02-06 17:06:56.508  3,5521,801145905,-;[ZTOP][ERR]usb read work bad, urb->status:-71\x0d
        02-06 17:06:56.509  4,5522,801145935,-;[ZTOP][WARN]Continuous logs will be suppressed from output\x0d
        02-06 17:06:56.522  3,5523,801159781,-;[ZTOP][ERR]usb read work bad, urb->status:-71\x0d
        02-06 17:06:56.523  4,5524,801159886,-;[ZTOP][WARN]Continuous logs will be suppressed from output\x0d
        02-06 17:06:56.535  3,5525,801173381,-;[ZTOP][ERR]usb read work bad, urb->status:-71\x0d
        02-06 17:06:56.535  4,5526,801173465,-;[ZTOP][WARN]Continuous logs will be suppressed from output\x0d
        02-06 17:06:56.544  6,5527,801182428,-;usb 1-3: USB disconnect, device number 3

结论:wpa_supplicant突然之间就接收到了接口被禁用的消息!这种问题一般是硬件模组的问题。

解决方案:

    1.更换模组硬件
    2.联合模组厂一起分析模组为什么突然disconnect了!

三.密码输入错误连接失败

问题现象描述:

    测试反馈连接手机热点,报密码错误!重新尝试连接正常。

日志分析:

    根本原因是是4次握手失败。愿意是密码确实是错误的!

        行 16006: 01-01 08:01:25.975  4798  4798 I C01560/WifiNAPIUtils: Call wifi func: ConnectToDevice (start)
        行 16024: 01-01 08:01:25.981  4156  4156 I C01560/WifiDeviceServiceImpl: CheckConfigPwd: keyMgmt = WPA-PSK!
        行 16025: 01-01 08:01:25.981  4156  4156 I C01560/WifiDeviceServiceImpl: CheckConfigPwd, ssid: 熊*************Pro, psk len: 9
        行 16028: 01-01 08:01:25.981  4156  4156 I C01560/WifiFrameWork: Enter Connect.
        行 16029: 01-01 08:01:25.981  4156  4156 I C01560/WifiFrameWork: Enter ConnectToDevice, ssid = 熊*************Pro instId:0. 
        行 16030: 01-01 08:01:25.981  4156  4156 I C01560/WifiFrameWork: Enter AddDeviceConfig, ssid:熊*************Pro, bssid=9c:51:**:**:**:37, keyMgmt: WPA-PSK
        
        行 16154: 01-01 08:01:26.023  3002  3002 I C01560/WifiHalStaInterface: Connect() networkid 0
        行 19776: 01-01 08:01:29.085  4398  4399 I C05200/wpa_supplicant:    selected BSS 9c:51:**:**:**:37 ssid='\xe****************************************Pro'
        
        行 19825: 01-01 08:01:29.139  4398  4399 I C05200/wpa_supplicant: SME: Trying to authenticate with 9c:51:**:**:**:37 (SSID='\xe****************************************Pro' freq=2437 MHz)
        行 19826: 01-01 08:01:29.139  4398  4399 I C05200/wpa_supplicant: wlan0: State: SCANNING -> AUTHENTICATING
        行 19906: 01-01 08:01:29.162  4398  4399 I C05200/wpa_supplicant: wlan0: Event AUTH (10) received
        行 19911: 01-01 08:01:29.163  4398  4399 I C05200/wpa_supplicant: Trying to associate with 9c:51:**:**:**:37 (SSID='\xe****************************************Pro' freq=2437 MHz)
        行 19912: 01-01 08:01:29.163  4398  4399 I C05200/wpa_supplicant: wlan0: State: AUTHENTICATING -> ASSOCIATING
        行 19950: 01-01 08:01:29.189  4398  4399 I C05200/wpa_supplicant: wlan0: Event ASSOC (0) received
        行 19960: 01-01 08:01:29.190  4398  4399 I C05200/wpa_supplicant: wlan0: State: ASSOCIATING -> ASSOCIATED
        行 19966: 01-01 08:01:29.191  4398  4399 I C05200/wpa_supplicant: wlan0: Associated with 9c:51:**:**:**:37
        行 20003: 01-01 08:01:29.214  4398  4399 I C05200/wpa_supplicant: wlan0: Event EAPOL_RX (23) received
        行 20005: 01-01 08:01:29.215  4398  4399 W C05200/wpa_supplicant: wlan0: RX EAPOL from 9c:51:**:**:**:37 (encrypted=0)
        行 20011: 01-01 08:01:29.216  4398  4399 I C05200/wpa_supplicant: wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE
        
        行 20429: 01-01 08:01:30.274  4398  4399 I C05200/wpa_supplicant: wlan0: Event EAPOL_RX (23) received
        行 20430: 01-01 08:01:30.274  4398  4399 W C05200/wpa_supplicant: wlan0: RX EAPOL from 9c:51:**:**:**:37 (encrypted=0)
        行 20431: 01-01 08:01:30.275  4398  4399 I C05200/wpa_supplicant: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
        
        行 20793: 01-01 08:01:31.310  4398  4399 I C05200/wpa_supplicant: wlan0: Event EAPOL_RX (23) received
        行 20794: 01-01 08:01:31.310  4398  4399 W C05200/wpa_supplicant: wlan0: RX EAPOL from 9c:51:**:**:**:37 (encrypted=0)
        行 20795: 01-01 08:01:31.311  4398  4399 I C05200/wpa_supplicant: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
        
        行 21118: 01-01 08:01:32.339  4398  4399 I C05200/wpa_supplicant: wlan0: Event EAPOL_RX (23) received
        行 21119: 01-01 08:01:32.339  4398  4399 W C05200/wpa_supplicant: wlan0: RX EAPOL from 9c:51:**:**:**:37 (encrypted=0)
        行 21120: 01-01 08:01:32.340  4398  4399 I C05200/wpa_supplicant: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
        
        行 21440: 01-01 08:01:33.374  4398  4399 I C05200/wpa_supplicant: wlan0: Event DISASSOC (1) received
        行 21443: 01-01 08:01:33.374  4398  4399 I C05200/wpa_supplicant: wlan0: Disassociation notification
        行 21444: 01-01 08:01:33.374  4398  4399 I C05200/wpa_supplicant: wlan0:  * reason 15 (4WAY_HANDSHAKE_TIMEOUT)
        行 21446: 01-01 08:01:33.375  4398  4399 I C05200/wpa_supplicant: Disassociation frame IE(s) - hexdump(len=0): [NULL]
        行 21447: 01-01 08:01:33.375  4398  4399 I C05200/wpa_supplicant: wlan0: CTRL-EVENT-DISCONNECTED bssid=9c:51:**:**:**:37 reason=15
        行 21448: 01-01 08:01:33.375  4398  4399 I C05200/wpa_supplicant: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
        
        行 21453: 01-01 08:01:33.375  4398  4399 I C05200/wpa_supplicant: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="" auth_failures=1 duration=10 reason=WRONG_KEY
        行 21458: 01-01 08:01:33.376  4398  4399 I C05200/wpa_supplicant: wlan0: Ignore connection failure indication since interface has been put into disconnected state
        行 21466: 01-01 08:01:33.376  4398  4399 I C05200/wpa_supplicant: wlan0: State: 4WAY_HANDSHAKE -> DISCONNECTED

解决方案:

    重新连接,输入正确的密码

 

Logo

社区规范:仅讨论OpenHarmony相关问题。

更多推荐