WiFi案例集锦

WiFi问题处理经验记录。

WiFi案例集锦racast无法连接

案例1 Miracast无法连接

问题描述

客户平台的网卡从一家厂商的芯片更换为另一家的芯片,结果出现WiFi Miracast无法连接成功的情况。

问题分析

初步信息调查:

  1. 客户平台内核版本为: 3.1.10
  2. 实测发现,当平台作GC时,连接没有问题。
  3. 分析手机端和平台端的 wpa_supplicant.log ,有如下一些发现:
    • 平台端如下Log异常: 2016031101.png Associaite Request中没有包含RSN IE等相关信息,这是P2P连接过程 中,所必须。
    • 手机端有如下Log异常:
       03-03 16:06:08.252 I/wpa_supplicant(  864): p2p0: WPS-M2D dev_password_id=0 config_error=12
       03-03 16:06:08.255 D/wpa_supplicant(  864): EAPOL: txSuppRsp
      03-03 16:06:08.255 D/wpa_supplicant(  864): TX EAPOL: dst=06:3d:98:a6:29:34
      03-03 16:06:08.255 D/wpa_supplicant(  864): TX EAPOL - hexdump(len=78): 01 00 00 4a 02 4d 00 4a fe 00 37 2a 00 00 00 01 02 00 10 4a 00 01 10 10 22 00 01 0d 10 1a 00 10 ...
      03-03 16:06:08.256 D/wpa_supplicant(  864): EAPOL: SUPP_BE entering state RECEIVE
      03-03 16:06:08.256 D/wpa_supplicant(  864): P2P: Terminate connection due to WPS PBC session overlap
      03-03 16:06:08.256 D/wpa_supplicant(  864): P2P: Group Formation failed with 06:3d:98:a6:29:34
      03-03 16:06:08.256 D/wpa_supplicant(  864): P2P: Clear timeout (state=PROVISIONING)
      03-03 16:06:08.256 D/wpa_supplicant(  864): P2P: State PROVISIONING -> IDLE
      03-03 16:06:08.256 I/wpa_supplicant(  864): P2P-GROUP-FORMATION-FAILURE
      

    config_error 的值为 12, 其意义为:  WPS_CFG_MULTIPLE_PBC_DETECTED ,这个是GO在处理M1信息时,带上的。

  4. 根据双方的Log, GO在处理GC发送过来的M1消息后,回复了M2D信息给GC, 从而中断了WPS的交互过程。从如下代码入手分析:

    2016031102.png

    函数 wps_registrar_p2p_dev_addr_match 中进行地址过滤时,发现了 线索:

    2016031103.png

    正常情况下, reg->p2p_dev_addr 的值应该与 wps->p2p_dev_addr 的值一致,但是从出错Log中发现 wps->p2p_dev_addr 的值为0。 而 wps 相关的初始化是在 eap_wsc_init 在调用了 wps_init 来进 行初始化的。 如下图所示 :

    2016031104.png

    有个条件引起来我们的注意: sm->assoc_p2p_ie 是否因为这个为NULL,导致 wps_init 初始化时, p2p_dev_addr 没有 得到赋值?

  5. 分析 wpa_supplicant 处理Associate Request的函数代码: 在函数 hostapd_notif_assoc 里面,会解析 Associate Request 携带 的IE信息, 代码如下:

    2016031105.png

    可以发现,并结合之前的Log发现, WPS, RSN, WPA等 IE信息都为空。 所以有理由 怀疑Driver送上来的Associate Request中就没有包含这些IE 信息, IE信息为空!!!

  6. Driver层确认 在Driver处理Association Request的地方, 加一些打印Log确认收到的 IE是否为空,结果发现,Driver有收到这些IE信息的。 Driver在处理完 Associate Request后,如果OK,会送回一个Associate Response给对方 ,并调用 cfg80211_new_sta 将Associate Request事件通知到上层。 应该在这个地方可能将IE信息漏掉了。

解决方法

由于定位到问题的原因是:驱动在调用 cfg80211_new_sta 时,没有将 如 下标记设置:

struct station_info sinfo;
struct ieee80211_mgmt *mgmt;

NdisZeroMemory(&sinfo, sizeof(sinfo));

//因为这个标记没有置上,导致nl80211模块处理IE信息时,
//将assoc_req IE给过滤掉了, 正解就是要让这句执行。
 sinfo.filled = STATION_INFO_ASSOC_REQ_IES;

 mgmt = (struct ieee80211_mgmt *) assoc_frame;
 sinfo.assoc_req_ies_len = assoc_len - 24 - 4;
sinfo.assoc_req_ies = mgmt->u.assoc_req.variable;

return cfg80211_new_sta(pNetDev, mac_addr, &sinfo, GFP_KERNEL);

案例2 p2p虚拟网络接口打开时,出现设备忙

问题描述

设备当GO时, p2p virtual interface 启动时,有时会出现Device or Resource is busy

问题分析

p2p 协商成功后,会创建一个virtual interface, 即 调用 wpa_driver_nl80211_if_add , 在该函数中,会调用 linux_set_iface_flags 将虚拟接口设置为UP状态, 查看该函数的代码如 下:

2016031106.png

在下这个命令时,出现上述错误。 kernel中处理该命令的函数为: devinet_ioctl 进一步追下去,在该函数中: __dev_change_flags 有如下代码:

2016031107.png

UP会对应 __dev_open 函数。 这个函数会调用driver注册的打开网络接口 的回调函数。如下代码所示 :

2016031108.png

从上述代码也可以看到,在打开设备之前,会发送一个 NETDEV_PRE_UP 通 知链消息。 在 cfg80211_netdev_notifier_call 函数中,会处理该消息: 这个逻辑主要是一些Sanity Check,即此时能不能打开该网络接口。

2016031109.png

最重要的处理函数是 cfg80211_can_use_iftype_chan ,在这个函数中会 分析当前打开网络接口是否有问题。

解决方法

通过对上述代码的分析,结合driver的Log,做出了如下的修改:

2016031110.png

案例3 在某个特定区域WiFi性能很差

问题描述

客户报怨仓库某个指定的区域WiFi性能很差,WiFi速率很慢。如下是抓包过程 中,某个数据帧的情况:

2016031401.png

问题分析

从上述抓包的信息来看,有两个信息值得注意:

  1. 信号干扰
  2. 重传

上述数据包是一个重传的数据包。 在Channel 6上重传概率大于30%。

2016031402.png

从WiSpy工具查看信号干扰情况,发现Channel 1~6 干扰很严重。

2016031403.png

解决方法

有发现周围有一个老旧的摄像机在周围,然而没有使用,但是通电着。这个摄 像机对Channel 1~6之间的信号干扰很大,导致出现较高的数据重传率。

案例4 固件升级后,手机出现奇怪现象

问题描述

固件升级后,一些手机出现奇怪的现象。 它们会连接到网络,然后断开并显 示定位网络服务的信息。这个过程是可重复的。

问题分析

数据包抓取结果如下:

2016031404.png

如上图红色标记,Duration的值太大,有点异常,一般情况下,应该只有几十 毫秒。

解决方法

这个问题最后查出是手机Firmware代码的Bug,导致在处理与802.11n的AP交互时, 出现Duration值异常的情况。这会影响周围所有的WiFi设备,而不仅仅是这个 手机。

案例5 WiFi性能差,且有时连接不上WiFi网络

问题描述

客户抱怨WiFi网络性能差,且有时甚至连接不上WiFi网络。

问题分析

抓包信息如下:

2016031405.png

可以看到出现了CRC错误, 这表明我的抓包工具不能正确地读取帧信息。当靠 近发送数据的设备时,CRC错误率会降低。

问题解决

当通信双方的距离大于一定值后,会出现CRC错误率变高的情况,尝试靠近一 下,看CRC错误率是否会降低。

案例6 客户报怨传输高分辨率的图片时很慢

问题描述

客户报怨他们新的网卡传输高分辨率的图片时,速率非常慢。然而,在上星期 的售前演示时,却没有这样的问题。

问题分析

抓取数据包如下:

2016031406.png

发现上述情况不断重复,即不停地进行Off-Channel扫描,然而网卡没有动, 且非常靠近AP。

一个设备在off-channel或休眠状态下是不会传输数据的。 NULL数据帧使用 power management位来通知AP为其缓存数据帧。 通常有如下两种原因:

  1. 节省电力
  2. 执行off-channel扫描来建立一个neighbor列表,以方便未来可能进行的漫 游动作。

在这个案例中,STA不停地尝试建立一个neighbor列表,可以看到它在正执行 off-channel扫描(在信息1,6,11之间不停地切换)。这表明STA正在尝试寻找 一个更好的AP去关联,有如下可能的原因会导致这种行为发生:

  1. driver有错误。
  2. STA错误地配置了高概率的漫游。
  3. RF差,没有接收到数据。
  4. 天线坏了或者是没有接好。
  5. 干涉。

解决方法

基于上述的分析以及可能的原因,发现USB接口的网卡插在显示器的背部,周 围几乎被金属包围。这样会导致USB性能很差,很能保持连接,会导致不停地 漫游到新的AP上。 2016031401.jpg

案例7 连接老旧AP热点失败

问题描述

连接一台比较旧的AP时,连接失败,被AP拒绝。对比其他平台,可以正常连接。

问题分析

这个问题看上去应该是AP兼容性问题,需要一份正常连接的Log和失败的Log进 行对比,以判断问题点。

  1. 首先看AP回的Probe Response的信息

    2016051301.png

    从图中,可以看到几个信息:

    • 此AP不包含HT Capability,说明是不支持11n的(注:在解决问题前, 是不清楚AP是很老旧的AP这个信息的。)
    • 第二,就是AP的一些Capability信息。
  2. 其次看下连接失败时,发送给AP的Association Request的包的信息

    2016051302.png

  3. 其他平台能正常连接到此AP时,发送给AP的Associaiton Request的包的信 息

    2016051303.png

通过对比,可以发现有如下两个疑点:

  1. Association Request中的immediate Bloack Ack Allowed这个位没有设置。
  2. 在发送给AP的Association Request中的信息中包含有Extended Capabilities信息。

解决方法

针对上述两个疑点,发现连接不上的主要原因是在Association Request中携 带了Extended Capabilities IE信息。针对这种情况, wpa_supplicant 已 经有了一个修改的思路:

/*
 * Workaround: Add Extended Capabilities element only if the AP
 * included this element in Beacon/Probe Response frames. Some older
 * APs seem to have interoperability issues if this element is
 * included, so while the standard may require us to include the
 * element in all cases, it is justifiable to skip it to avoid
 * interoperability issues.
 */
if (!bss || wpa_bss_get_ie(bss, WLAN_EID_EXT_CAPAB)) {
        u8 ext_capab[18];
        int ext_capab_len;
        ext_capab_len = wpas_build_ext_capab(wpa_s, ext_capab,
                                             sizeof(ext_capab));
        if (ext_capab_len > 0) {
                u8 *pos = wpa_ie;
                if (wpa_ie_len > 0 && pos[0] == WLAN_EID_RSN)
                        pos += 2 + pos[1];
                os_memmove(pos + ext_capab_len, pos,
                           wpa_ie_len - (pos - wpa_ie));
                wpa_ie_len += ext_capab_len;
                os_memcpy(pos, ext_capab, ext_capab_len);
        }
}

案例8 A模下吞吐量偏低的问题

问题描述

客户 有报在A模下吞吐量偏低的问题, 标准要求在20MBit/s, 但是测试到的结果低于10Mbit/s.

问题分析

当在A模式下,设置AP在某些channel, driver会识别成其他的 Channel,这时吞吐量会偏低。

在Side Band Channel听到比较弱的AP Beacon

解决方法

过滤到非Ajacent信道上侦听到的Beacon。

案例9 p2p go失败后,导致wlan断开

问题描述

When we are doing concurrent p2p connection (STA + P2P-GO) using dynamic interface, after some trails the GO-NEG fails which is causing the STA connection to be deauthenticated.

问题分析

  1. NEG_FAIL 失败的原因 the reason for failing the add_iface is because we have exceeded the maximum number of VIF's. So we are ok with p2p GO-NEG failing, but the problem is it disconnects the STA interface.
  2. 问题初步分析
    • It looks like some of the calls in at least one of the error paths end up getting going through both p2p-wlan0-# and wlan0 interface when handling this type of failure case. The pending p2p-wlan0-# instance gets removed properly, but wlan0 instance should not have tried to remove the pending P2P group since it was not on that instance in the first place.
    • The reason for GO-NEG fail is that "add_iface" is failing, so "p2p_group_interface" is not set, but in wpas_p2p_group_delete based on the below condition we are deleting the STA managed interface. wpas_p2p_group_delete() should not be called on the non-P2P station interface.
      else if (wpa_s->p2p_group_interface == P2P_GROUP_INTERFACE_CLIENT ||
                        (ssid && ssid->mode == WPAS_MODE_INFRA)) {
                       wpa_s->reassociate = 0;
                       wpa_s->disconnected = 1;
                       gtype = "client";
      

      Is there any reason for checking INFRA mode in p2p module? Yes, WPAS_MODE_INFRA is used for P2P Client as well as non-P2P station.

解决方案

It was possible for a P2P group formation failure to result in a concurrent station mode operation getting disconnected in the specific error case where group interface addition fails after a successful GO Negotiation. Fix this by skipping the wpas_p2p_group_delete() call in this specific case since the group interface does not exists anymore at the point wpas_group_formation_completed() gets called.

案例10 Miracast过程中,视频卡住

问题描述

当TV与RealTek的测试设备进行Miracast连接时,Miracast播放视频卡住。

问题分析

现象梳理

  1. P2P established successfully p2p连接成功
  2. Data Transmission over p2p is ok 相互之间是可以Ping通的
  3. 从Video播放的日志来看, Video frame rate应该为30fps,但是实际 10fps都不到,且A/V一直在Drop Frame,这表明从Driver端收到的数据 不够快。
  4. 这个问题只在2.4G的情况下出现 ,5G情况下不会出现。
  5. 对比测试有如下现象:
    • Dut run on 5GHz: Pass
    • Dut act as GO: Pass
    • Dut act as GC: Fail

    怀疑管理帧有带错东西导致送数据的速率很低。 这个是Probe Request相关信息: 2016072001.png

问题根源

  1. Realtek testbed transmit data frame using 40MHz in 2.4G (check with sniffer)
  2. DUT is forced 20MHz Bandwidth in 2.4G

问题解决

在GC与GO关联的过程中,在Association Request显示设置 HtCapability IE ,根据情况,将ChannelWidth设置为20MHz

static VOID ApCliMlmeAssocReqAction(IN PRTMP_ADAPTER pAd, IN MLME_QUEUE_ELEM * Elem)
{
…..
#ifdef CUSTOMIZED_BW_SETTING
                        if (RTMP_GetCustomizedChannelBw(pAd,
                                apcli_entry->wdev.channel) == HT_BW_20) {
                                HtCapabilityTmp.HtCapInfo.ChannelWidth = BW_20;
                        }
#endif /* CUSTOMIZED_BW_SETTING */
...
  }

案例11 TCP RX enhancement

问题描述

  XXX BCM43569
TCP RX Avg 220 Peek 250 257
UDP RX Avg 285 Peek 299 280

与对比平台相比,TCP吞吐量罗低。

问题分析

在跟TCP RX时,出现很多Bulkout Pending, 如下图所示: 2016080302.png 怀疑可能是因为TCP ack TX过慢(波动较大)

问题解决

针对TCP ack包,提高它的优先级. 2016080303.png

案例12 hostapd启动时报错: nl80211: setkey failed

问题描述

在启动hostapd时,失败,有如下Log出现:

D/hostapd ( 2058): random: Got 5/20 bytes from /dev/random
I/hostapd ( 2058): random: Only 5/20 bytes of strong random data available from /dev/random
I/hostapd ( 2058): random: Not enough entropy pool available for secure operations
I/hostapd ( 2058): WPA: Not enough entropy in random pool for secure operations - update keys later when the first station connects
D/hostapd ( 2058): GMK - hexdump(len=32): [REMOVED]
D/hostapd ( 2058): Key Counter - hexdump(len=32): [REMOVED]
D/hostapd ( 2058): WPA: Delay group state machine start until Beacon frames have been configured
D/hostapd ( 2058): WPS: Building WPS IE for (Re)Association Response
D/hostapd ( 2058): WPS:  * Version (hardcoded 0x10)
D/hostapd ( 2058): WPS:  * Response Type (3)
D/hostapd ( 2058): WPS:  * Version2 (0x20)
D/hostapd ( 2058): nl80211: Set beacon (beacon_set=0)
D/hostapd ( 2058): WPA: Start group state machine to set initial keys
D/hostapd ( 2058): WPA: group state machine entering state GTK_INIT (VLAN-ID 0)
D/hostapd ( 2058): GTK - hexdump(len=16): [REMOVED]
D/hostapd ( 2058): WPA: group state machine entering state SETKEYSDONE (VLAN-ID 0)
D/hostapd ( 2058): wpa_driver_nl80211_set_key: ifindex=6 alg=3 addr=0x4006f0f1 key_idx=1 set_tx=1 seq_len=0 key_len=16
D/hostapd ( 2058):    broadcast key
D/hostapd ( 2058): nl80211: set_key failed; err=-2 No such file or directory)
D/hostapd ( 2058): wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)

问题分析

因为Secure Key会通过 "/dev/random"去对Kernel做存储,SoftAp会透过这 种方法去储存和产生所有的Key Number。

hostapd去产生一个随机的dummy key时,产生错误,所以在调用 set key时 自然会失败。

问题解决

失败的原因与Kernel中的一个选项有关: CONFIG_CRYPTO_ANSI_CPRNG , 打开该选项后,就不会有这个问题。 另外, 配置文件中,wpa应该设置为0或者不显示设置, 当wpa的值设置不正 确时,会出现下述错误。

interface=wlan0 
driver=nl80211 
ssid=woody_hostap
hw_mode=g 
channel=6 
ieee80211n=1
#wpa=0
wpa_passphrase=12345678
wpa_key_mgmt=WPA-PSK 
wpa_pairwise=TKIP CCMP
wpa_ptk_rekey=600

案例13 TV连接不上Hidden SSID AP

问题描述

TP-LINK路由器将2.4G设置为Hidden, MT7662T连接2.4G不成功;将5G设置为Hidden却可以连接成功

问题分析

使用手机连接2.4G Hidden AP, 每次都能成功,可以比对TV与手机两者间的 Probe request frame有何差异.

环境:

  • TP-LINK双频路由一台,MS938+MT7662T开发板一块,红米3S手机一台
  • MAC地址

    TPLINK路由器: 8C:21:0A:F3:D5:72

    MT7662 MAC: 00:6C:FD:AB:68:E2

    红米3S手机: 74:23:44:82:5A:63

Sniffer Log分析情况:

  1. AP一直没回复probe response给TV。
  2. 但是与手机连接时,却正常回复了probe response。
  3. 对比TV和SP连接的probe request frame 发现TV多了HT CAP/WPS/P2P IE, 查看AP是能支持 11n的, 猜测比较可能出现不兼容 的是WPS IE

    2016090201.png

    Figure 19: TV连接失败的log

    2016090202.png

    Figure 20: SP连接成功的log
  4. 去掉WPS IE后进行测试 测试结果表明AP不接收TV发的WPS IE,属兼容性问题
  5. AP为何不能接收TV的WPS IE 现场有找到 一台使用MT7601的TV,发现是可以正常连接的, 对比了 MT7662T的WPS IE, 发现RF Bands的值有所不一样

    2016090203.png

    Figure 21: MT7601

    2016090204.png

    Figure 22: MT7662T
  6. 修改RF Bands测试 修改MT7662T Probe request WPS IE的RF Bands 值为1进行测试,发现 每次都能连接成功

    MT7662T是支持2.4/5G的,因此不建议将RF Bands设置为1.

问题解决

参考SP,station 在AP scan时Probe request不把WPS IE包进去

Probe request是否要带WPS IE, 需要看下面API的返回值 2016090205.png

默认情况下,发送Probe Request的时候不把WPS IE包含进来,但是当进行 Miracast/P2P连接时,动态打开限制,把WPS IE包含进来。这个逻辑通过上 层传递一个参数进来即可。

案例14 手机与TV进行Miracast连接,TCP连接失败

问题描述

开机后,连接AP,然后使用WFD投屏, 投屏失败,退出WFD。

问题分析

  1. 程序日志分析 查看连接过程中的日志,发现:
    P2P-GROUP-STARTED p2p1 client ssid="DIRECT-uc-minote" 
    

    这个日志出现说明p2p连接是成功的,问题可能出现在后面。

    继续后面,有看到dhcp交互过程也正常,TV有请求到IP地址,这说明问 题出现在RTSP交互阶段。

    Lease of 192.168.49.30 obtained, lease time 3600
    

    在RTSP会话建立时,TV要通过TCP协议连接到7236这个端口上,但是连接 失败:

    WfdRtspClient::buildTcpConnection tcp connect failed
    
  2. tcpdump日志分析 TCP连接涉及三步握手过程,通过tcpdump可以分析一下这个过程是否成 功。 2016120801.png

    TV这边一直在重传三步握手中的第一包数据SYN。是TV没有将数据传出去 还是手机一直没有回应?

  3. Sniffer日志分析 Sniffer日志可以查看最终从硬件发出去的数据。 通过抓取WiFi Sniffer日志,发现并没有看到TV发出来的第一包握手包数据。看来是TV 这端的问题。接下来要确认问题是出现在驱动还是FW: 打印从驱动向FW送数据前的日志,确认驱动有将数据往FW送。

问题解决

最终确认问题发生在FW这边,FW没有将数据送出去。更新FW后,问题解决。

案例15 WPA: 4-Way Handshake failed, PSK may be incorrect

问题描述

当通过 wpa_supplicant 跟某个AP进行连接时,出现4步握手错误,不断 重复打印日志 如下:

...
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Scan requested (ret=0) - scan timeout 30 seconds
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b19 len=8
Received 3891 bytes of scan results (9 BSSes)
CTRL-EVENT-SCAN-RESULTS 
Selecting BSS from priority group 0
Try to find WPA-enabled AP
0: 00:27:19:fd:ca:94 ssid='XXXXXXXX' wpa_ie_len=0 rsn_ie_len=20 caps=0x11
   skip - SSID mismatch
   skip - SSID mismatch
   skip - SSID mismatch
   selected based on RSN IE
   selected WPA AP 00:27:19:fd:ca:94 ssid='XXXXXXXX'
Trying to associate with 00:27:19:fd:ca:94 (SSID='XXXXXXXX' freq=2412 MHz)
Cancelling scan request
WPA: clearing own WPA/RSN IE
Automatic auth_alg selection: 0x1
RSN: using IEEE 802.11i/D9.0
WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 01 00
WPA: using GTK CCMP
WPA: using PTK CCMP
WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
No keys have been configured - skip key clearing
wpa_driver_wext_set_drop_unencrypted
State: SCANNING -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
wpa_driver_wext_set_psk
Setting authentication timeout: 10 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: External notification - EAP fail=0
EAPOL: External notification - portControl=Auto
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b04 len=12
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b1a len=16
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8c08 len=24
AssocResp IE wireless event - hexdump(len=16): 01 08 82 84 8b 96 0c 18 30 48 32 04 12 24 60 6c
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:27:19:fd:ca:94
Association info event
resp_ies - hexdump(len=16): 01 08 82 84 8b 96 0c 18 30 48 32 04 12 24 60 6c
State: ASSOCIATING -> ASSOCIATED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
Associated to a new BSS: BSSID=00:27:19:fd:ca:94
No keys have been configured - skip key clearing
Associated with 00:27:19:fd:ca:94
WPA: Association event - clear replay counter
WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
Setting authentication timeout: 10 sec 0 usec
Cancelling scan request
RX EAPOL from 00:27:19:fd:ca:94
Setting authentication timeout: 10 sec 0 usec
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=2
  key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=16 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
  key_nonce - hexdump(len=32): af a0 0b 03 51 8b 24 56 a1 2b 35 21 8f 94 94 85 27 26 76 33 6c 7e b0 cf 2f 14 19 
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:27:19:fd:ca:94 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: Renewed SNonce - hexdump(len=32): 6d e5 7b a9 a6 3a 7e 8e b7 c8 a2 40 d1 f1 9c 6e 76 73 50 ec e1 77 84 38 0
WPA: PTK derivation - A1=00:80:48:3d:5d:60 A2=00:27:19:fd:ca:94
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
RX EAPOL from 00:27:19:fd:ca:94
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=2
  key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=16 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
  key_nonce - hexdump(len=32): af a0 0b 03 51 8b 24 56 a1 2b 35 21 8f 94 94 85 27 26 76 33 6c 7e b0 cf 2f 14 19 
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:27:19:fd:ca:94 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=00:80:48:3d:5d:60 A2=00:27:19:fd:ca:94
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
RX EAPOL from 00:27:19:fd:ca:94
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=2
  key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=16 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
  key_nonce - hexdump(len=32): af a0 0b 03 51 8b 24 56 a1 2b 35 21 8f 94 94 85 27 26 76 33 6c 7e b0 cf 2f 14 19 
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:27:19:fd:ca:94 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=00:80:48:3d:5d:60 A2=00:27:19:fd:ca:94
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
EAPOL: startWhen --> 0
EAPOL: disable timer tick
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: enable timer tick
EAPOL: txStart
WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
RX EAPOL from 00:27:19:fd:ca:94
IEEE 802.1X RX: version=1 type=3 length=95
  EAPOL-Key type=2
  key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
  key_length=16 key_data_length=0
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04
  key_nonce - hexdump(len=32): af a0 0b 03 51 8b 24 56 a1 2b 35 21 8f 94 94 85 27 26 76 33 6c 7e b0 cf 2f 14 19 
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:27:19:fd:ca:94 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=00:80:48:3d:5d:60 A2=00:27:19:fd:ca:94
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:00:00:00:00:00
WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Setting scan request: 0 sec 100000 usec
BSSID 00:27:19:fd:ca:94 blacklist count incremented to 2
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
State: 4WAY_HANDSHAKE -> DISCONNECTED
...

... and again from the top.

一直报: "WPA: 4-Way Handshake failed - pre-shared key may be incorrect"

问题分析

从日志的字面上理解,可能是我们提供的密码有错。但是,再三确认过,输 入的密码是正确的。

wpa_supplicant 的网络配置如下:

$ wpa_passphrase "test" "passphrase"
network={
        ssid="test"
        #psk="passphrase"
        psk=a8f6fbf02bfbd7ddd27249ac101487ff51c245b2c34c2efe46b6e680b367ee32
}

Note

psk 使用明文表示时,则 wpa_supplicant 在第一次读取配置文件 时,会实时生成一个 256-bit 的十六进制的 psk 。当然我们也可以通过 wpa_passphrase 程序提供生成 256-bit 的十六进制的 psk ,直接写 在配置文件中。

遇到日志报密码不正确的问题时,有如下几个Check点:

  1. 换一种 psk 的写法,交叉对比测试一下。
  2. 检查 psk 是否有特殊字符存在。
  3. 通过Sniffer Log看下是否底层传递数据的问题。

问题解决

当使用明文的方式 配置 psk 的时候,连接就正常了。