greearb / ath10k-ct

Stand-alone ath10k driver based on Candela Technologies Linux kernel.
111 stars 41 forks source link

IBSS WPA2 "failed to delete peer" #15

Closed ghost closed 5 years ago

ghost commented 7 years ago

Software (OS, Firmware version, kernel, driver, etc) OpenWRT Chaos, Calmer Kernel 3.18, driver 1df6b26, fw 18

Hardware (NIC chipset, platform, etc) QCA9882

Logs (dmesg, maybe supplicant and/or hostap) [ 25.780000] ath10k_pci 0000:01:00.0: 10.1 wmi init: vdevs: 16 peers: 127 tid: 256 [ 25.800000] ath10k_pci 0000:01:00.0: wmi print 'P 128 V 8 T 410' [ 25.810000] ath10k_pci 0000:01:00.0: wmi print 'msdu-desc: 1424 sw-crypt: 0' [ 25.810000] ath10k_pci 0000:01:00.0: wmi print 'alloc rem: 25908 iram: 25760' [ 25.930000] ath10k_pci 0000:01:00.0: no channel configured; ignoring frame(s)! [ 25.940000] ath10k_pci 0000:01:00.0: no channel configured; ignoring frame(s)! [ 25.950000] device ap0 entered promiscuous mode [ 25.960000] ath10k_pci 0000:01:00.0: no channel configured; ignoring frame(s)! [ 25.980000] br-lan: port 1(ap0) entered forwarding state [ 25.980000] br-lan: port 1(ap0) entered forwarding state [ 26.280000] device ap1 entered promiscuous mode [ 26.280000] br-lan: port 2(ap1) entered forwarding state [ 26.290000] br-lan: port 2(ap1) entered forwarding state [ 26.350000] batman_adv: bat0: Interface activated: adhoc0 [ 26.750000] batman_adv: bat0: Interface deactivated: adhoc0 [ 26.770000] batman_adv: bat0: Interface activated: adhoc0 [ 26.930000] batman_adv: bat0: Interface activated: adhoc1 [ 26.930000] batman_adv: bat0: Interface deactivated: adhoc0 [ 27.000000] br-lan: port 1(ap0) entered disabled state [ 27.000000] batman_adv: bat0: Interface activated: adhoc0 [ 27.010000] adhoc0: Created IBSS using preconfigured BSSID ba:f2:be:e9:36:ab [ 27.020000] adhoc0: Creating new IBSS network, BSSID ba:f2:be:e9:36:ab [ 27.290000] br-lan: port 1(ap0) entered forwarding state [ 27.300000] br-lan: port 1(ap0) entered forwarding state [ 40.110000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:13:c3:72 for vdev 1: -145 [ 40.120000] ------------[ cut here ]------------ [ 40.120000] WARNING: CPU: 0 PID: 8 at /mnt/ssd0/dev-hotspot/jjp-jwap230/chaos-calmer-15.05.1/build_dir/target-mips_74kc_uClibc-0.9.33.2/linux-ar71xx_generic/compat-wireless-2016-01-10/net/mac80211/sta_info.c:934 sta_set_sinfo+0x994/0xa24 [mac80211]() [ 40.150000] Modules linked in: ppp_async snd_usb_audio ppp_generic asix xt_time xt_recent xt_id xt_comment xt_TCPMSS xt_LOG xt_CT usbnet usbhid snd_usbmidi_lib slhc nf_log_ipv4 nf_log_common nf_conntrack_rtcache iptable_raw hid_generic crc_ccitt cdc_acm act_mirred em_u32 cls_route hid evdev input_core batman_adv libcrc32c xt_set ip_set_list_set ip_set_hash_netiface ip_set_hash_netport ip_set_hash_netnet ip_set_hash_net ip_set_hash_netportnet ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set ifb snd_compress snd_pcm_oss snd_mixer_oss snd_pcm snd_timer snd_rawmidi snd_seq_device snd_hwdep snd soundcore ath9k ath9k_common ath9k_hw ath10k_pci ath10k_core ath mac80211 cfg80211 compat arc4 crypto_blkcipher ehci_platform ehci_hcd usbcore nls_base usb_common crc16 mii crc32c_generic crypto_hash [ 40.240000] CPU: 0 PID: 8 Comm: kworker/u2:1 Not tainted 3.18.45 #1 [ 40.250000] Workqueue: phy0 ieee80211_ibss_leave [mac80211] [ 40.250000] Stack : 803f40f0 00000001 8785e780 80357330 870070e0 000003a6 8705ad4c 803b0000 [ 40.250000] 86e01468 00000004 8705ba78 800a67f4 00000008 80098614 8782a430 803b0000 [ 40.250000] 80383ad0 8787399c 8787399c 800a67f4 00000003 80095d1c 8705ad4c 878739a8 [ 40.250000] 0000010c 801e6674 00000000 00000000 00000000 00000000 00000000 00000000 [ 40.250000] 70687930 00000000 00000000 00000000 00000000 00000000 87b31800 87b31900 [ 40.250000] ... [ 40.290000] Call Trace: [ 40.290000] [<800715ac>] show_stack+0x50/0x84 [ 40.300000] [<8008128c>] warn_slowpath_common+0x84/0xb4 [ 40.310000] [<80081340>] warn_slowpath_null+0x18/0x24 [ 40.310000] [<870070e0>] sta_set_sinfo+0x994/0xa24 [mac80211] [ 40.320000] [ 40.320000] ---[ end trace 54fb589b6ecbf851 ]--- [ 43.330000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:13:c3:72 for vdev 1: -145 [ 46.340000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:14:53:fd for vdev 1: -145 [ 49.340000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:14:53:fd for vdev 1: -145 [ 52.340000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:14:53:fd for vdev 1: -145 [ 55.340000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:14:53:fd for vdev 1: -145 [ 58.360000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:13:c3:72 for vdev 1: -145 [ 61.370000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:13:c3:72 for vdev 1: -145 [ 64.390000] ath10k_pci 0000:01:00.0: failed to delete peer 06:ca:6d:13:c3:72 for vdev 1: -145 [ 64.400000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 64.400000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 64.410000] ------------[ cut here ]------------ [ 64.420000] WARNING: CPU: 0 PID: 8 at /mnt/ssd0/dev-hotspot/jjp-jwap230/chaos-calmer-15.05.1/build_dir/target-mips_74kc_uClibc-0.9.33.2/linux-ar71xx_generic/compat-wireless-2016-01-10/net/mac80211/sta_info.c:926 sta_set_sinfo+0x92c/0xa24 [mac80211]() [ 64.440000] Modules linked in: ppp_async snd_usb_audio ppp_generic asix xt_time xt_recent xt_id xt_comment xt_TCPMSS xt_LOG xt_CT usbnet usbhid snd_usbmidi_lib slhc nf_log_ipv4 nf_log_common nf_conntrack_rtcache iptable_raw hid_generic crc_ccitt cdc_acm act_mirred em_u32 cls_route hid evdev input_core batman_adv libcrc32c xt_set ip_set_list_set ip_set_hash_netiface ip_set_hash_netport ip_set_hash_netnet ip_set_hash_net ip_set_hash_netportnet ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set ifb snd_compress snd_pcm_oss snd_mixer_oss snd_pcm snd_timer snd_rawmidi snd_seq_device snd_hwdep snd soundcore ath9k ath9k_common ath9k_hw ath10k_pci ath10k_core ath mac80211 cfg80211 compat arc4 crypto_blkcipher ehci_platform ehci_hcd usbcore nls_base usb_common crc16 mii crc32c_generic crypto_hash [ 64.530000] CPU: 0 PID: 8 Comm: kworker/u2:1 Tainted: G W 3.18.45 #1 [ 64.540000] Workqueue: phy0 ieee80211_ibss_leave [mac80211] [ 64.550000] Stack : 803f40f0 00000001 8785e780 80357330 87007078 0000039e 8705ad4c 803b0000 [ 64.550000] 86e01468 00000004 8705ba78 800a67f4 00000008 80098614 8782a430 803b0000 [ 64.550000] 80383ad0 8787399c 8787399c 800a67f4 00000003 80095d1c 8705ad4c 878739a8 [ 64.550000] 00000124 801e6674 00000000 00000000 00000000 00000000 00000000 00000000 [ 64.550000] 70687930 00000000 00000000 00000000 00000000 00000000 87b31800 87b31900 [ 64.550000] ... [ 64.590000] Call Trace: [ 64.590000] [<800715ac>] show_stack+0x50/0x84 [ 64.600000] [<8008128c>] warn_slowpath_common+0x84/0xb4 [ 64.600000] [<80081340>] warn_slowpath_null+0x18/0x24 [ 64.610000] [<87007078>] sta_set_sinfo+0x92c/0xa24 [mac80211] [ 64.610000] [ 64.620000] ---[ end trace 54fb589b6ecbf852 ]--- [ 65.640000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 65.650000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 65.670000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 65.670000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 65.680000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 65.690000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 65.710000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 65.710000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 65.720000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 65.730000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 67.750000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.760000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:55:04 vdev 1: -2 [ 67.780000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.780000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 67.800000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.810000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:55:04 vdev 1: -2 [ 67.830000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.830000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 67.850000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.860000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 67.880000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 67.890000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 68.090000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 68.100000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:13:c3:72 vdev 1: -2 [ 91.550000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.550000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.570000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.570000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.580000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.590000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.610000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.610000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.620000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.630000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.650000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.650000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 91.660000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 91.670000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 96.160000] batman_adv: bat0: hop_penalty: Changing from: 20 to: 15 [ 333.490000] ath10k_pci 0000:01:00.0: failed to install key for non-existent peer 06:ca:6d:14:53:fd [ 343.510000] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 1: -2 [ 343.520000] ath10k_pci 0000:01:00.0: failed to disassociate station: 06:ca:6d:14:53:fd vdev 1: -2 [ 1031.680000] ------------[ cut here ]------------ [ 1031.680000] WARNING: CPU: 0 PID: 2645 at /mnt/ssd0/dev-hotspot/jjp-jwap230/chaos-calmer-15.05.1/build_dir/target-mips_74kc_uClibc-0.9.33.2/linux-ar71xx_generic/compat-wireless-2016-01-10/net/mac80211/ibss.c:1079 ieee80211_get_vht_mask_from_cap+0x1970/0x1ca8 [mac80211]() [ 1031.710000] Modules linked in: ppp_async snd_usb_audio ppp_generic asix xt_time xt_recent xt_id xt_comment xt_TCPMSS xt_LOG xt_CT usbnet usbhid snd_usbmidi_lib slhc nf_log_ipv4 nf_log_common nf_conntrack_rtcache iptable_raw hid_generic crc_ccitt cdc_acm act_mirred em_u32 cls_route hid evdev input_core batman_adv libcrc32c xt_set ip_set_list_set ip_set_hash_netiface ip_set_hash_netport ip_set_hash_netnet ip_set_hash_net ip_set_hash_netportnet ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set ifb snd_compress snd_pcm_oss snd_mixer_oss snd_pcm snd_timer snd_rawmidi snd_seq_device snd_hwdep snd soundcore ath9k ath9k_common ath9k_hw ath10k_pci ath10k_core ath mac80211 cfg80211 compat arc4 crypto_blkcipher ehci_platform ehci_hcd usbcore nls_base usb_common crc16 mii crc32c_generic crypto_hash [ 1031.790000] CPU: 0 PID: 2645 Comm: kworker/u2:4 Tainted: G W 3.18.45 #1 [ 1031.800000] Workqueue: phy1 ieee80211_ibss_leave [mac80211] [ 1031.810000] Stack : 803f40f0 00000001 86114180 80357330 87012bb8 00000437 8705ba78 85adc6e8 [ 1031.810000] 87a5a000 871b307a 00000fff 800a67f4 00000a55 80098614 8612d0d0 85adc6e8 [ 1031.810000] 80383ad0 85adbad4 85adbad4 800a67f4 00000003 80095d1c 8705ba78 85adbae0 [ 1031.810000] 0000015c 801e6674 00000000 00000000 00000000 00000000 00000000 00000000 [ 1031.810000] 70687931 00000000 00000000 00000000 00000000 00000000 87365000 87365200 [ 1031.810000] ... [ 1031.840000] Call Trace: [ 1031.850000] [<800715ac>] show_stack+0x50/0x84 [ 1031.850000] [<8008128c>] warn_slowpath_common+0x84/0xb4 [ 1031.860000] [<80081340>] warn_slowpath_null+0x18/0x24 [ 1031.860000] [<87012bb8>] ieee80211_get_vht_mask_from_cap+0x1970/0x1ca8 [mac80211] [ 1031.870000] [ 1031.870000] ---[ end trace 54fb589b6ecbf853 ]---

greearb commented 7 years ago

errno 145 looks like a timeout, so maybe firmware is hung, or WMI msg bus is out of buffers, or some other such issue.

At least with recent ath10k-ct driver, we should purposefully crash the firmware when there is a timeout like this, so that the system can recover.

int ath10k_wmi_cmd_send(struct ath10k ar, struct sk_buff skb, u32 cmd_id) { int ret = -EOPNOTSUPP; int retry = 1000;

might_sleep();

if (cmd_id == WMI_CMD_UNSUPPORTED) {
    ath10k_warn(ar, "wmi command %d is not supported by firmware\n",
            cmd_id);
    dev_kfree_skb_any(skb);
    return ret;
}

wait_event_timeout(ar->wmi.tx_credits_wq, ({
    /* try to send pending beacons first. they take priority */
    ath10k_wmi_tx_beacons_nowait(ar);

    while (--retry) {
        ret = ath10k_wmi_cmd_send_nowait(ar, skb, cmd_id);
        if ((ret == -ENOBUFS) &&
            !test_bit(ATH10K_FLAG_CRASH_FLUSH, &ar->dev_flags)) {
            /* CE transport logic is full, maybe we cannot reap entries fast
             * enough?
             */
            ath10k_err(ar, "CE transport is full, sleeping for 1ms\n");
            msleep(1);
            continue;
        }
        break;
    }

    if (ret && test_bit(ATH10K_FLAG_CRASH_FLUSH, &ar->dev_flags))
        ret = -ESHUTDOWN;

    (ret != -EAGAIN);
}), 3 * HZ);

if (ret)
    dev_kfree_skb_any(skb);

if (ret == -EAGAIN) {
    /* Firmware is not responding after 3 seconds, might as well try to kill it. */
    ath10k_err(ar, "Cannot communicate with firmware, attempting to fake crash and restart firmware.\n");
    ath10k_hif_fw_crashed_dump(ar);
    set_bit(ATH10K_FLAG_CRASH_FLUSH, &ar->dev_flags);
}

return ret;

}

Maybe EAGAIN should also check for ETIMEDOUT here? Can you make changes to the driver to test this? And, how reproducible is this?

ghost commented 7 years ago

This is 100% reproducible but this a field issue, I'm not able to reproduce it myself. I can try your change of course.

greearb commented 6 years ago

New ath10k-ct driver and firmware was recently accepted into LEDE/OpenWRT. Please re-test with that if you can and see if problems remain?

ghost commented 6 years ago

Using the latest driver, the latest firmware and the following patch, it seems to work:

--- a/ath10k/wmi.c +++ b/ath10k/wmi.c @@ -1883,7 +1883,7 @@ if (ret) dev_kfree_skb_any(skb);

greearb commented 5 years ago

Hello... At least in recent code I do not see why we would need to check for ETIMEDOUT. Please re-open if you think 4.19 ct driver needs this.