Modify

Opened 2 years ago

Last modified 21 months ago

#20854 reopened defect

ath10k "failed to delete peer" kernel errors causing wireless failure

Reported by: hancockrwd@… Owned by: developers
Priority: normal Milestone:
Component: kernel Version: Trunk
Keywords: Cc:

Description

Running Designated Driver r47161 on a TP-Link Archer C7 v2.

Since I got a new Nexus 5X phone, I've started seeing occasional kernel errors like this in the log and the 5GHz wireless stops functioning:

Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.276312] ath10k_pci 0000:01:00.0: failed to delete peer 64:bc:0c:46:e4:55 for vdev 0: -145
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.285049] ------------[ cut here ]------------
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.289969] WARNING: CPU: 0 PID: 1969 at /home/rob/openwrt/build_dir/target-mips_34kc_musl-1.1.11/linux-ar71xx_generic/compat-wireless-2015-07-21/net/mac80211/sta_info.c:923 sta_set_sinfo+0x7b8/0x850 [mac80211]()
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.309258] Modules linked in: pppoe ppp_async iptable_nat ath9k pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE ath9k_common xt_time xt_tcpudp xt_tcpmss xt_string xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_id xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_DSCP xt_CT xt_CLASSIFY usblp ts_kTue Nov  3 19:00:19 2015 kern.warn kernel: [205839.460106] CPU: 0 PID: 1969 Comm: hostapd Not tainted 4.1.10 #2
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] Stack : 803e42d2 00000034 00000000 00000001 8033cc04 80388723 878f79d0 000007b1
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] 	  803e3524 00000000 00000004 00000008 00000000 800a5da4 00000003 80341f78
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] 	  0000039b 00000000 8034048c 869117e4 00000000 800a442c 803e42d2 000000c8
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] 	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] 	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.466302] 	  ...
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.502819] Call Trace:
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.505411] [<80072124>] show_stack+0x50/0x84
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.509951] [<800819ec>] warn_slowpath_common+0xa0/0xd0
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.515340] [<80081aa4>] warn_slowpath_null+0x18/0x24
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.520931] [<872861a4>] sta_set_sinfo+0x7b8/0x850 [mac80211]
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.526951] 
Tue Nov  3 19:00:19 2015 kern.warn kernel: [205839.528552] ---[ end trace 4c11a7e0ac3e8ff8 ]---
Tue Nov  3 19:00:19 2015 daemon.info hostapd: wlan0: STA 64:bc:0c:46:e4:55 IEEE 802.11: deauthenticated due to local deauth request
Tue Nov  3 19:05:28 2015 daemon.info hostapd: wlan0: STA 20:68:9d:69:c3:78 IEEE 802.11: disassociated due to inactivity
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.205045] ath10k_pci 0000:01:00.0: failed to install key for vdev 0 peer 20:68:9d:69:c3:78: -145
Tue Nov  3 19:05:31 2015 kern.err kernel: [206151.214242] wlan0: failed to remove key (0, 20:68:9d:69:c3:78) from hardware (-145)
Tue Nov  3 19:05:31 2015 daemon.info hostapd: wlan0: STA 20:68:9d:69:c3:78 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.223351] ath10k_pci 0000:01:00.0: cipher 0 is not supported
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.229432] ath10k_pci 0000:01:00.0: failed to remove peer wep key 0: -122
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.236590] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 0: -122
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.244805] ath10k_pci 0000:01:00.0: failed to disassociate station: 20:68:9d:69:c3:78 vdev 0: -122
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.254091] ------------[ cut here ]------------
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.258991] WARNING: CPU: 0 PID: 1969 at /home/rob/openwrt/build_dir/target-mips_34kc_musl-1.1.11/linux-ar71xx_generic/compat-wireless-2015-07-21/net/mac80211/sta_info.c:915 sta_set_sinfo+0x768/0x850 [mac80211]()
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.278219] Modules linked in: pppoe ppp_async iptable_nat ath9k pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE ath9k_common xt_time xt_tcpudp xt_tcpmss xt_string xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_id xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_DSCP xt_CT xt_CLASSIFY usblp ts_kTue Nov  3 19:05:31 2015 kern.warn kernel: [206151.428912] CPU: 0 PID: 1969 Comm: hostapd Tainted: G        W       4.1.10 #2
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] Stack : 803e42d2 00000042 00000000 00000001 8033cc04 80388723 878f79d0 000007b1
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] 	  803e3524 00000000 00000004 00000008 00000000 800a5da4 00000003 80341f78
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] 	  00000393 00000000 8034048c 869117e4 00000000 800a442c 803e42d2 000000c8
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] 	  80387890 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] 	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.436334] 	  ...
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.472804] Call Trace:
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.475423] [<80072124>] show_stack+0x50/0x84
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.479957] [<800819ec>] warn_slowpath_common+0xa0/0xd0
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.485371] [<80081aa4>] warn_slowpath_null+0x18/0x24
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.490689] [<87286154>] sta_set_sinfo+0x768/0x850 [mac80211]
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.496656] 
Tue Nov  3 19:05:31 2015 kern.warn kernel: [206151.498256] ---[ end trace 4c11a7e0ac3e8ff9 ]---
Tue Nov  3 19:05:34 2015 kern.warn kernel: [206154.494938] ath10k_pci 0000:01:00.0: failed to delete peer 20:68:9d:69:c3:78 for vdev 0: -11
Tue Nov  3 19:05:37 2015 kern.warn kernel: [206157.504828] ath10k_pci 0000:01:00.0: failed to set beacon mode for vdev 0: -11
Tue Nov  3 19:05:40 2015 kern.warn kernel: [206160.504714] ath10k_pci 0000:01:00.0: failed to set dtim period for vdev 0: -11
Tue Nov  3 19:05:43 2015 kern.warn kernel: [206163.514603] ath10k_pci 0000:01:00.0: failed to recalculate rts/cts prot for vdev 0: -11
Tue Nov  3 19:05:46 2015 kern.warn kernel: [206166.514504] ath10k_pci 0000:01:00.0: failed to set protection mode 0 on vdev 0: -11
Tue Nov  3 19:05:49 2015 kern.warn kernel: [206169.514387] ath10k_pci 0000:01:00.0: failed to set preamble for vdev 0: -11

Attachments (0)

Change History (20)

comment:1 Changed 2 years ago by nbd

please provide a full kernel log (e.g. dmesg output), not just the messages from when this error started.

comment:2 Changed 2 years ago by robstoon

I tried updating to r47397 but had the same issue. Here's the full log.

[    0.000000] Linux version 4.1.11 (rob@haswell) (gcc version 4.8.3 (OpenWrt/Linaro GCC 4.8-2014.04 r47397) ) #2 Fri Nov 6 19:13:48 CST 2015
[    0.000000] MyLoader: sysp=fdfbfbfe, boardp=feef7ff7, parts=7ffdddfd
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019750 (MIPS 74Kc)
[    0.000000] SoC: Qualcomm Atheros QCA9558 ver 1 rev 0
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 08000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] On node 0 totalpages: 32768
[    0.000000] free_area_init_node: node 0, pgdat 80387de0, node_mem_map 81000000
[    0.000000]   Normal zone: 256 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 32768 pages, LIFO batch:7
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line:  board=ARCHER-C7  console=ttyS0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 125724K/131072K available (2705K kernel code, 132K rwdata, 492K rodata, 244K init, 195K bss, 5348K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:83
[    0.000000] Clocks: CPU:720.000MHz, DDR:600.000MHz, AHB:200.000MHz, Ref:40.000MHz
[    0.000000] clocksource MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 5309056796 ns
[    0.000007] sched_clock: 32 bits at 360MHz, resolution 2ns, wraps every 5965232126ns
[    0.007494] Calibrating delay loop... 358.80 BogoMIPS (lpj=1794048)
[    0.070069] pid_max: default: 32768 minimum: 301
[    0.074616] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.080950] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.089791] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.099691] NET: Registered protocol family 16
[    0.104900] MIPS: machine is TP-LINK Archer C7
[    0.112241] ar724x-pci ar724x-pci.0: PCIe link is down
[    0.117138] registering PCI controller with io_map_base unset
[    0.122818] registering PCI controller with io_map_base unset
[    0.570262] PCI host bridge to bus 0000:00
[    0.574190] pci_bus 0000:00: root bus resource [mem 0x10000000-0x11ffffff]
[    0.580791] pci_bus 0000:00: root bus resource [io  0x0000]
[    0.586173] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
[    0.592714] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.600386] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[    0.600493] PCI host bridge to bus 0000:01
[    0.604374] pci_bus 0000:01: root bus resource [mem 0x12000000-0x13ffffff]
[    0.611025] pci_bus 0000:01: root bus resource [io  0x0001]
[    0.616385] pci_bus 0000:01: root bus resource [??? 0x00000000 flags 0x0]
[    0.622945] pci_bus 0000:01: No busn resource found for root bus, will use [bus 01-ff]
[    0.630614] pci 0000:01:00.0: [168c:003c] type 00 class 0x028000
[    0.630656] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit]
[    0.630710] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[    0.630761] pci 0000:01:00.0: supports D1 D2
[    0.630929] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    0.630956] pci 0000:01:00.0: BAR 0: assigned [mem 0x12000000-0x121fffff 64bit]
[    0.637988] pci 0000:01:00.0: BAR 6: assigned [mem 0x12200000-0x1220ffff pref]
[    0.644924] pci 0000:01:00.0: using irq 41 for pin 1
[    0.650334] Switched to clocksource MIPS
[    0.655078] NET: Registered protocol family 2
[    0.659947] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.666646] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.672771] TCP: Hash tables configured (established 1024 bind 1024)
[    0.678941] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.684553] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.690802] NET: Registered protocol family 1
[    0.695003] PCI: CLS 0 bytes, default 32
[    0.695788] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.715155] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.720764] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.732434] io scheduler noop registered
[    0.736158] io scheduler deadline registered (default)
[    0.741318] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.747710] console [ttyS0] disabled
[    0.771167] serial8250.0: ttyS0 at MMIO 0x18020000 (irq = 11, base_baud = 2500000) is a 16550A
[    0.779430] console [ttyS0] enabled
[    0.786473] bootconsole [early0] disabled
[    0.796641] m25p80 spi0.0: found s25fl128s, expected m25p80
[    0.802344] m25p80 spi0.0: s25fl128s (16384 Kbytes)
[    0.808273] 5 tp-link partitions found on MTD device spi0.0
[    0.813958] Creating 5 MTD partitions on "spi0.0":
[    0.818817] 0x000000000000-0x000000020000 : "u-boot"
[    0.824556] 0x000000020000-0x000000145410 : "kernel"
[    0.830226] 0x000000145410-0x000000ff0000 : "rootfs"
[    0.835926] mtd: device 2 (rootfs) set to be root filesystem
[    0.841739] 1 squashfs-split partitions found on MTD device rootfs
[    0.848006] 0x000000810000-0x000000ff0000 : "rootfs_data"
[    0.854109] 0x000000ff0000-0x000001000000 : "art"
[    0.859505] 0x000000020000-0x000000ff0000 : "firmware"
[    0.878558] switch0: Atheros AR8327 rev. 4 switch registered on ag71xx-mdio.0
[    0.968232] libphy: ag71xx_mdio: probed
[    1.561841] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.0:00 [uid=004dd034, driver=Atheros AR8216/AR8236/AR8316]
[    1.573155] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:RGMII
[    2.161928] eth1: Atheros AG71xx at 0xba000000, irq 5, mode:SGMII
[    2.169974] NET: Registered protocol family 10
[    2.177521] NET: Registered protocol family 17
[    2.182140] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
[    2.195063] 8021q: 802.1Q VLAN Support v1.8
[    2.206007] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    2.214066] Freeing unused kernel memory: 244K (803a3000 - 803e0000)
[    3.302448] init: Console is alive
[    3.306067] init: - watchdog -
[    5.170168] usbcore: registered new interface driver usbfs
[    5.175841] usbcore: registered new interface driver hub
[    5.181340] usbcore: registered new device driver usb
[    5.217629] SCSI subsystem initialized
[    5.226141] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    5.233933] ehci-platform: EHCI generic platform driver
[    5.239305] ehci-platform ehci-platform.0: EHCI Host Controller
[    5.245373] ehci-platform ehci-platform.0: new USB bus registered, assigned bus number 1
[    5.255639] ehci-platform ehci-platform.0: TX-TX IDP fix enabled
[    5.261758] ehci-platform ehci-platform.0: irq 48, io mem 0x1b000000
[    5.280394] ehci-platform ehci-platform.0: USB 2.0 started, EHCI 1.00
[    5.287611] hub 1-0:1.0: USB hub found
[    5.291703] hub 1-0:1.0: 1 port detected
[    5.295972] ehci-platform ehci-platform.1: EHCI Host Controller
[    5.302041] ehci-platform ehci-platform.1: new USB bus registered, assigned bus number 2
[    5.312328] ehci-platform ehci-platform.1: TX-TX IDP fix enabled
[    5.318433] ehci-platform ehci-platform.1: irq 49, io mem 0x1b400000
[    5.340357] ehci-platform ehci-platform.1: USB 2.0 started, EHCI 1.00
[    5.347582] hub 2-0:1.0: USB hub found
[    5.351673] hub 2-0:1.0: 1 port detected
[    5.357954] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    5.365304] ohci-platform: OHCI generic platform driver
[    5.373937] usbcore: registered new interface driver usb-storage
[    6.327488] init: - preinit -
[    7.457758] eth1: link up (1000Mbps/Full duplex)
[    7.479186] random: procd urandom read with 11 bits of entropy available
[    9.691240] jffs2_scan_eraseblock(): End of filesystem marker found at 0x10000
[    9.698593] jffs2_build_filesystem(): unlocking the mtd device... done.
[    9.705323] jffs2_build_filesystem(): erasing all blocks after the end marker... done.
[   35.582050] jffs2: notice: (421) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[   35.600056] mount_root: overlay filesystem has not been fully initialized yet
[   35.622116] mount_root: switching to jffs2 overlay
[   36.417605] eth1: link down
[   36.429278] procd: - early -
[   36.432755] procd: - watchdog -
[   37.114600] procd: - ubus -
[   38.131293] procd: - init -
[   39.755417] sit: IPv6 over IPv4 tunneling driver
[   39.781809] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   39.806282] Netfilter messages via NETLINK v0.30.
[   39.822108] ip_set: protocol 6
[   39.892131] Loading modules backported from Linux version master-2015-10-26-0-g28c26cb
[   39.900163] Backport generated by backports.git backports-20150903-4-g12cf266
[   39.946899] cfg80211: World regulatory domain updated:
[   39.952155] cfg80211:  DFS Master region: unset
[   39.956573] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   39.966462] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   39.974590] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   39.982716] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[   39.990846] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[   40.000473] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[   40.010088] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[   40.018300] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[   40.026422] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[   40.197787] PCI: Enabling device 0000:01:00.0 (0000 -> 0002)
[   40.206052] ath10k_pci 0000:01:00.0: pci irq legacy interrupts 0 irq_mode 0 reset_mode 0
[   40.424955] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/cal-pci-0000:01:00.0.bin failed with error -2
[   40.435487] ath10k_pci 0000:01:00.0: Falling back to user helper
[   47.824999] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/board-2.bin failed with error -2
[   47.835603] ath10k_pci 0000:01:00.0: Falling back to user helper
[   47.909137] firmware ath10k!QCA988X!hw2.0!board-2.bin: firmware_loading_store: map pages failed
[   48.952798] ath10k_pci 0000:01:00.0: qca988x hw2.0 (0x4100016c, 0x043202ff sub 0000:0000) fw 10.2.4.70-2 fwapi 5 bdapi 1 htt-ver 2.1 wmi-op 5 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1 features no-p2p
[   48.971250] ath10k_pci 0000:01:00.0: debug 0 debugfs 1 tracing 0 dfs 1 testmode 1
[   49.073330] ath: EEPROM regdomain: 0x0
[   49.073344] ath: EEPROM indicates default country code should be used
[   49.073351] ath: doing EEPROM country->regdmn map search
[   49.073368] ath: country maps to regdmn code: 0x3a
[   49.073377] ath: Country alpha2 being used: US
[   49.073384] ath: Regpair used: 0x3a
[   49.084806] cfg80211: Regulatory domain changed to country: US
[   49.090754] cfg80211:  DFS Master region: FCC
[   49.094994] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   49.104883] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
[   49.113012] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (N/A)
[   49.122636] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2300 mBm), (0 s)
[   49.132257] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2300 mBm), (0 s)
[   49.140467] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[   49.148579] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
[   49.321549] u32 classifier
[   49.324303]     input device check on
[   49.328015]     Actions configured
[   49.333525] Mirror/redirect action on
[   49.345180] nf_conntrack version 0.5.0 (1968 buckets, 7872 max)
[   49.431031] ip_tables: (C) 2000-2006 Netfilter Core Team
[   49.498783] usbcore: registered new interface driver usblp
[   49.541194] xt_time: kernel timezone is -0000
[   49.562392] PPP generic driver version 2.4.2
[   49.569154] NET: Registered protocol family 24
[   49.588769] ath: EEPROM regdomain: 0x0
[   49.588786] ath: EEPROM indicates default country code should be used
[   49.588793] ath: doing EEPROM country->regdmn map search
[   49.588810] ath: country maps to regdmn code: 0x3a
[   49.588819] ath: Country alpha2 being used: US
[   49.588827] ath: Regpair used: 0x3a
[   49.602252] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[   49.604647] ieee80211 phy1: Atheros AR9550 Rev:0 mem=0xb8100000, irq=47
[   57.140725] eth1: link up (1000Mbps/Full duplex)
[   57.158885] device eth1 entered promiscuous mode
[   57.171135] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[   57.203413] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   58.232000] br-lan: port 1(eth1) entered forwarding state
[   58.237527] br-lan: port 1(eth1) entered forwarding state
[   58.284610] cfg80211: Regulatory domain changed to country: CA
[   58.290571] cfg80211:  DFS Master region: FCC
[   58.294813] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   58.304708] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 3000 mBm), (N/A)
[   58.312832] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 1700 mBm), (N/A)
[   58.322460] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2400 mBm), (0 s)
[   58.332086] cfg80211:   (5490000 KHz - 5600000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s)
[   58.340197] cfg80211:   (5650000 KHz - 5730000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s)
[   58.348322] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A)
[   58.655019] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   60.230369] br-lan: port 1(eth1) entered forwarding state
[   60.260888] eth0: link up (1000Mbps/Full duplex)
[   62.120018] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   62.127295] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   62.167836] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   62.213830] device wlan0 entered promiscuous mode
[   62.261092] Atheros AR8216/AR8236/AR8316 ag71xx-mdio.0:00: Port 1 is up
[   62.269142] Atheros AR8216/AR8236/AR8316 ag71xx-mdio.0:00: Port 5 is up
[   62.333558] device wlan1 entered promiscuous mode
[   62.338395] br-lan: port 3(wlan1) entered forwarding state
[   62.344014] br-lan: port 3(wlan1) entered forwarding state
[   63.120569] br-lan: port 3(wlan1) entered disabled state
[   64.050399] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   64.056989] br-lan: port 2(wlan0) entered forwarding state
[   64.062612] br-lan: port 2(wlan0) entered forwarding state
[   66.060370] br-lan: port 2(wlan0) entered forwarding state
[   71.815252] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   71.821920] br-lan: port 3(wlan1) entered forwarding state
[   71.827524] br-lan: port 3(wlan1) entered forwarding state
[   71.959631] random: nonblocking pool is initialized
[   73.820366] br-lan: port 3(wlan1) entered forwarding state
[ 1622.881675] Atheros AR8216/AR8236/AR8316 ag71xx-mdio.0:00: Port 4 is up
[ 1872.447808] ath10k_pci 0000:01:00.0: failed to delete peer 64:bc:0c:46:e4:55 for vdev 0: -145
[ 1872.456456] ------------[ cut here ]------------
[ 1872.461289] WARNING: CPU: 0 PID: 2159 at /home/rob/openwrt/build_dir/target-mips_34kc_musl-1.1.11/linux-ar71xx_generic/compat-wireless-2015-10-26/net/mac80211/sta_info.c:918 sta_set_sinfo+0x938/0x9d0 [mac80211]()
[ 1872.480434] Modules linked in: pppoe ppp_async iptable_nat ath9k pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE ath9k_common xt_time xt_tcpudp xt_tcpmss xt_string xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_id xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_DSCP xt_CT xt_CLASSIFY usblp ts_kmp ts_fsm ts_bm slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_nat_ftp nf_nat nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack_ftp iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt ath9k_hw em_cmp em_nbyte sch_teql sch_dsmark sch_tbf sch_pie act_ipt sch_gred sch_htb cls_basic sch_prio
[ 1872.552989]  em_meta act_police em_text sch_codel sch_fq sch_sfq sch_red act_connmark nf_conntrack act_skbedit act_mirred em_u32 cls_u32 cls_tcindex cls_flow cls_route cls_fw sch_hfsc sch_ingress ath10k_pci ath10k_core ath mac80211 cfg80211 compat ledtrig_usbdev 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 nfnetlink ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_raw ip6table_mangle ip6table_filter ip6_tables x_tables msdos ifb sit tunnel4 ip_tunnel vfat fat usb_storage ohci_platform ohci_hcd ehci_platform ehci_hcd sd_mod scsi_mod gpio_button_hotplug
[ 1872.625088]  ext4 jbd2 mbcache usbcore nls_base usb_common crc16 crypto_hash
[ 1872.631011] CPU: 0 PID: 2159 Comm: hostapd Not tainted 4.1.11 #2
[ 1872.637099] Stack : 803e42d2 00000034 00000000 00000001 8033cbac 80388723 8799afc0 0000086f
	  803e3524 00000000 00000004 00000008 00000000 800a5d34 00000003 80341f20
	  00000396 00000000 80340434 858177e4 00000000 800a43bc 803e42d2 000000c8
	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  ...
[ 1872.673496] Call Trace:
[ 1872.675991] [<80072124>] show_stack+0x50/0x84
[ 1872.680437] [<800819ec>] warn_slowpath_common+0xa0/0xd0
[ 1872.685784] [<80081aa4>] warn_slowpath_null+0x18/0x24
[ 1872.691035] [<873869ec>] sta_set_sinfo+0x938/0x9d0 [mac80211]

[ 1872.698439] ---[ end trace 6751cc6390d26847 ]---
[ 2178.626996] ath10k_pci 0000:01:00.0: failed to install key for vdev 0 peer 8c:3a:e3:15:29:f3: -145
[ 2178.636103] wlan0: failed to remove key (0, 8c:3a:e3:15:29:f3) from hardware (-145)
[ 2178.657904] ath10k_pci 0000:01:00.0: cipher 0 is not supported
[ 2178.663879] ath10k_pci 0000:01:00.0: failed to remove peer wep key 0: -122
[ 2178.670920] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 0: -122
[ 2178.679067] ath10k_pci 0000:01:00.0: failed to disassociate station: 8c:3a:e3:15:29:f3 vdev 0: -122
[ 2178.688309] ------------[ cut here ]------------
[ 2178.693108] WARNING: CPU: 0 PID: 2159 at /home/rob/openwrt/build_dir/target-mips_34kc_musl-1.1.11/linux-ar71xx_generic/compat-wireless-2015-10-26/net/mac80211/sta_info.c:910 sta_set_sinfo+0x8e8/0x9d0 [mac80211]()
[ 2178.712266] Modules linked in: pppoe ppp_async iptable_nat ath9k pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE ath9k_common xt_time xt_tcpudp xt_tcpmss xt_string xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_id xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_DSCP xt_CT xt_CLASSIFY usblp ts_kmp ts_fsm ts_bm slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_nat_ftp nf_nat nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack_ftp iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt ath9k_hw em_cmp em_nbyte sch_teql sch_dsmark sch_tbf sch_pie act_ipt sch_gred sch_htb cls_basic sch_prio
[ 2178.784793]  em_meta act_police em_text sch_codel sch_fq sch_sfq sch_red act_connmark nf_conntrack act_skbedit act_mirred em_u32 cls_u32 cls_tcindex cls_flow cls_route cls_fw sch_hfsc sch_ingress ath10k_pci ath10k_core ath mac80211 cfg80211 compat ledtrig_usbdev 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 nfnetlink ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_raw ip6table_mangle ip6table_filter ip6_tables x_tables msdos ifb sit tunnel4 ip_tunnel vfat fat usb_storage ohci_platform ohci_hcd ehci_platform ehci_hcd sd_mod scsi_mod gpio_button_hotplug
[ 2178.856831]  ext4 jbd2 mbcache usbcore nls_base usb_common crc16 crypto_hash
[ 2178.862745] CPU: 0 PID: 2159 Comm: hostapd Tainted: G        W       4.1.11 #2
[ 2178.870085] Stack : 803e42d2 00000042 00000000 00000001 8033cbac 80388723 8799afc0 0000086f
	  803e3524 00000000 00000004 00000008 00000000 800a5d34 00000003 80341f20
	  0000038e 00000000 80340434 858177e4 00000000 800a43bc 803e42d2 000000c8
	  80387890 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  ...
[ 2178.906727] Call Trace:
[ 2178.909253] [<80072124>] show_stack+0x50/0x84
[ 2178.913681] [<800819ec>] warn_slowpath_common+0xa0/0xd0
[ 2178.919009] [<80081aa4>] warn_slowpath_null+0x18/0x24
[ 2178.924239] [<8738699c>] sta_set_sinfo+0x8e8/0x9d0 [mac80211]

[ 2178.931641] ---[ end trace 6751cc6390d26848 ]---
[ 2181.926812] ath10k_pci 0000:01:00.0: failed to delete peer 8c:3a:e3:15:29:f3 for vdev 0: -11
[ 2184.946721] ath10k_pci 0000:01:00.0: failed to set beacon mode for vdev 0: -11
[ 2187.946538] ath10k_pci 0000:01:00.0: failed to set dtim period for vdev 0: -11
[ 2190.986373] ath10k_pci 0000:01:00.0: failed to recalculate rts/cts prot for vdev 0: -11
[ 2193.986210] ath10k_pci 0000:01:00.0: failed to set protection mode 0 on vdev 0: -11
[ 2196.986045] ath10k_pci 0000:01:00.0: failed to set preamble for vdev 0: -11

comment:3 Changed 2 years ago by nbd

please try current trunk

comment:4 Changed 2 years ago by anonymous

Hi ndb, with last trunk r47373, ath10k couldn't load firmware:

[ 13.296760] PCI: Enabling device 0000:01:00.0 (0000 -> 0002)
[ 13.302965] ath10k_pci 0000:01:00.0: pci irq legacy interrupts 0 irq_mode 0 reset_mode 0
[ 13.527777] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/cal-pci-0000:01:00.0.bin failed with error -2
[ 13.538311] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 13.632564] firmware ath10kcal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed
[ 13.641530] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-5.bin failed with error -2
[ 13.652411] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 13.731577] firmware ath10k!QCA988X!hw2.0!firmware-5.bin: firmware_loading_store: map pages failed
[ 13.740799] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-5.bin': -11
[ 13.750952] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-4.bin failed with error -2
[ 13.761815] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 13.839816] firmware ath10k!QCA988X!hw2.0!firmware-4.bin: firmware_loading_store: map pages failed
[ 13.849097] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-4.bin': -11
[ 13.859234] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-3.bin failed with error -2
[ 13.870093] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 13.950631] firmware ath10k!QCA988X!hw2.0!firmware-3.bin: firmware_loading_store: map pages failed
[ 13.959907] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-3.bin': -11
[ 13.970043] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware-2.bin failed with error -2
[ 13.980902] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 14.058508] firmware ath10k!QCA988X!hw2.0!firmware-2.bin: firmware_loading_store: map pages failed
[ 14.067783] ath10k_pci 0000:01:00.0: could not fetch firmware file 'ath10k/QCA988X/hw2.0/firmware-2.bin': -11
[ 14.077913] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/firmware.bin failed with error -2
[ 14.088597] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 14.167789] firmware ath10k!QCA988X!hw2.0!firmware.bin: firmware_loading_store: map pages failed
[ 14.176884] ath10k_pci 0000:01:00.0: could not fetch firmware (-11)
[ 14.183272] ath10k_pci 0000:01:00.0: could not fetch firmware files (-11)
[ 14.190158] ath10k_pci 0000:01:00.0: could not probe fw (-11)

comment:5 Changed 2 years ago by nbd

did you run make oldconfig after updating?
the package ath10k-firmware-qca988x needs to be selected

comment:6 Changed 2 years ago by anonymous

Sorry my english nbd, but what do you mean by "run make oldconfig".
I installed trunk with sysupgrade and run "opkg install kmod-ath10k" as always did. Do I need to install some other package?

comment:7 Changed 2 years ago by nbd

also do 'opkg install ath10k-firmware-qca988x' then

comment:8 Changed 2 years ago by anonymous

Worked perfectly!
Thanks

comment:9 Changed 2 years ago by nbd

  • Resolution set to fixed
  • Status changed from new to closed

comment:10 Changed 2 years ago by robstoon

I'm actually the original reporter. I've been running for a few days after just updating the firmware version for QCA988X from 10.2.4.70-2 to 10.2.4.70.10-2 and haven't had any more errors. Will submit a patch shortly.

comment:11 Changed 2 years ago by robstoon

  • Resolution fixed deleted
  • Status changed from closed to reopened

Unfortunately the newer firmware version and updating to r47452 didn't seem to solve the issue. It may be working somewhat more reliably, perhaps (hard to say as it happens sporadically), but it's still happening. Any other ideas?

[   48.612363] ath10k_pci 0000:01:00.0: qca988x hw2.0 (0x4100016c, 0x043202ff sub 0000:0000) fw 10.2.4.70.10-2 fwapi 5 bdapi 1 htt-ver 2.1 wmi-op 5 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1 features no-p2p,raw-mode

..

[72071.328152] ath10k_pci 0000:01:00.0: failed to delete peer 64:bc:0c:46:e4:55 for vdev 0: -145
[72071.336819] ------------[ cut here ]------------
[72071.341644] WARNING: CPU: 0 PID: 2189 at /home/rob/openwrt/build_dir/target-mips_34kc_musl-1.1.11/linux-ar71xx_generic/compat-wireless-2015-10-26/net/mac80211/sta_info.c:918 sta_set_sinfo+0x938/0x9d0 [mac80211]()
[72071.360803] Modules linked in: pppoe ppp_async iptable_nat ath9k pppox ppp_generic nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ipv4 ipt_REJECT ipt_MASQUERADE ath9k_common xt_time xt_tcpudp xt_tcpmss xt_string xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_id xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_DSCP xt_CT xt_CLASSIFY usblp ts_kmp ts_fsm ts_bm slhc nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_nat_ftp nf_nat nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack_ftp iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt ath9k_hw em_cmp em_nbyte sch_teql sch_dsmark sch_tbf sch_pie act_ipt sch_gred sch_htb cls_basic sch_prio
[72071.433472]  em_meta act_police em_text sch_codel sch_fq sch_sfq sch_red act_connmark nf_conntrack act_skbedit act_mirred em_u32 cls_u32 cls_tcindex cls_flow cls_route cls_fw sch_hfsc sch_ingress ath10k_pci ath10k_core ath mac80211 cfg80211 compat ledtrig_usbdev 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 nfnetlink ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 nf_log_common ip6table_raw ip6table_mangle ip6table_filter ip6_tables x_tables msdos ifb sit tunnel4 ip_tunnel vfat fat usb_storage ohci_platform ohci_hcd ehci_platform ehci_hcd sd_mod scsi_mod gpio_button_hotplug
[72071.505606]  ext4 jbd2 mbcache usbcore nls_base usb_common crc16 crypto_hash
[72071.511521] CPU: 0 PID: 2189 Comm: hostapd Not tainted 4.1.11 #2
[72071.517609] Stack : 803e42d2 00000034 00000000 00000001 8033cd38 80388723 878f6ab8 0000088d
	  803e352c 00000000 00000004 00000008 00000000 800a5d90 00000003 803420ac
	  00000396 00000000 803405c0 86a317e4 00000000 800a4418 803e42d2 000000c8
	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
	  ...
[72071.554023] Call Trace:
[72071.556520] [<80072180>] show_stack+0x50/0x84
[72071.560964] [<80081a48>] warn_slowpath_common+0xa0/0xd0
[72071.566297] [<80081b00>] warn_slowpath_null+0x18/0x24
[72071.571548] [<873869ec>] sta_set_sinfo+0x938/0x9d0 [mac80211]

[72071.578995] ---[ end trace 8a40faa59ba0f534 ]---
[72387.104598] ath10k_pci 0000:01:00.0: failed to install key for vdev 0 peer 8c:3a:e3:15:29:f3: -145
[72387.113708] wlan0: failed to remove key (0, 8c:3a:e3:15:29:f3) from hardware (-145)
[72387.129423] ath10k_pci 0000:01:00.0: cipher 0 is not supported
[72387.135418] ath10k_pci 0000:01:00.0: failed to remove peer wep key 0: -122
[72387.142395] ath10k_pci 0000:01:00.0: failed to clear all peer wep keys for vdev 0: -122
[72387.150541] ath10k_pci 0000:01:00.0: failed to disassociate station: 8c:3a:e3:15:29:f3 vdev 0: -122

comment:12 Changed 2 years ago by robstoon

Looks like 10.2.4.70.12-2 just showed up in ath10k-firmware git. I'll try that one and see if it works any better.

comment:13 Changed 2 years ago by robstoon

This appears to be fixed with the new 10.2.4.70-12.2 firmware, which has been switched to in r47469. Think this can be closed now.

comment:14 follow-up: Changed 2 years ago by anonymous

Still happens for me with 10.2.4.70.12-2:

[    0.000000] Linux version 4.1.11 (xdarklight@blackbox) (gcc version 4.8.3 (OpenWrt/Linaro GCC 4.8-2014.04 r47327) ) #27 Sat Nov 7 14:53:50 CET 2015
[    0.000000] SoC: VR9 rev 1.2
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019556 (MIPS 34Kc)
[    0.000000] MIPS: machine is BTHOMEHUBV5A - BT Home Hub 5A
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 08000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] On node 0 totalpages: 32768
[    0.000000] free_area_init_node: node 0, pgdat 8054dd30, node_mem_map 81008a20
[    0.000000]   Normal zone: 256 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 32768 pages, LIFO batch:7
[    0.000000] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: console=ttyLTQ0,115200 init=/etc/preinit
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Writing ErrCtl register=00021800
[    0.000000] Readback ErrCtl register=00021800
[    0.000000] Memory: 123896K/131072K available (4080K kernel code, 264K rwdata, 1076K rodata, 256K init, 261K bss, 7176K reserved, 0K cma-reserved)
[    0.000000] NR_IRQS:256
[    0.000000] CPU Clock: 500MHz
[    0.000000] clocksource MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041786 ns
[    0.000011] sched_clock: 32 bits at 250MHz, resolution 4ns, wraps every 8589934590ns
[    0.008260] Calibrating delay loop... 332.54 BogoMIPS (lpj=665088)
[    0.042332] pid_max: default: 32768 minimum: 301
[    0.047339] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.053821] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.067656] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.077426] pinctrl core: initialized pinctrl subsystem
[    0.083253] NET: Registered protocol family 16
[    0.092709] pinctrl-xway 1e100b10.pinmux: Init done
[    0.098280] dma-xway 1e104100.dma: Init done - hw rev: 7, ports: 7, channels: 28
[    0.208615] dcdc-xrx200 1f106a00.dcdc: Core Voltage : 1016 mV
[    0.231817] PCI host bridge /fpi@10000000/pci@E105400 ranges:
[    0.237467]  MEM 0x0000000018000000..0x0000000019ffffff
[    0.242717]   IO 0x000000001ae00000..0x000000001affffff
[    0.366120] ath9k,eeprom ath9k_eep: failed to load eeprom address
[    0.395543] usbcore: registered new interface driver usbfs
[    0.401040] usbcore: registered new interface driver hub
[    0.406419] usbcore: registered new device driver usb
[    0.411772] PCI host bridge to bus 0000:00
[    0.415760] pci_bus 0000:00: root bus resource [mem 0x18000000-0x19ffffff]
[    0.422670] pci_bus 0000:00: root bus resource [io  0xffffffff]
[    0.428661] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
[    0.435515] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.443571] pci 0000:00:0e.0: [168c:ff1d] type 00 class 0x020000
[    0.443625] pci 0000:00:0e.0: reg 0x10: [mem 0x00000000-0x0000ffff]
[    0.444049] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[    0.444096] pci 0000:00:0e.0: BAR 0: assigned [mem 0x18000000-0x1800ffff]
[    0.450958] PCI host bridge to bus 0000:01
[    0.454939] pci_bus 0000:01: root bus resource [mem 0x1c000000-0x1cffffff]
[    0.461854] pci_bus 0000:01: root bus resource [io  0x1d800000-0x1d8fffff]
[    0.468798] pci_bus 0000:01: root bus resource [??? 0x00000000 flags 0x0]
[    0.475653] pci_bus 0000:01: No busn resource found for root bus, will use [bus 01-ff]
[    0.483683] pci 0000:01:00.0: [1bef:0011] type 01 class 0x060000
[    0.483708] ifx_pcie_rc_class_early_fixup: fixed pcie host bridge to pci-pci bridge
[    0.501465] pci 0000:01:00.0: PME# supported from D0 D3hot
[    0.501812] pci 0000:01:00.0: bridge configuration invalid ([bus 02-00]), reconfiguring
[    0.509985] pci 0000:02:00.0: [168c:003c] type 00 class 0x028000
[    0.510059] pci 0000:02:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit]
[    0.510138] pci 0000:02:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[    0.510242] pci 0000:02:00.0: supports D1 D2
[    0.510524] pci_bus 0000:02: busn_res: [bus 02-ff] end is updated to 02
[    0.510563] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 02
[    0.510621] pci 0000:01:00.0: BAR 8: assigned [mem 0x1c000000-0x1c1fffff]
[    0.517301] pci 0000:01:00.0: BAR 9: assigned [mem 0x1c200000-0x1c2fffff pref]
[    0.524570] pci 0000:02:00.0: BAR 0: assigned [mem 0x1c000000-0x1c1fffff 64bit]
[    0.531970] pci 0000:02:00.0: BAR 6: assigned [mem 0x1c200000-0x1c20ffff pref]
[    0.539230] pci 0000:01:00.0: PCI bridge to [bus 02]
[    0.544265] pci 0000:01:00.0:   bridge window [mem 0x1c000000-0x1c1fffff]
[    0.551120] pci 0000:01:00.0:   bridge window [mem 0x1c200000-0x1c2fffff pref]
[    0.558493] ifx_pcie_bios_map_irq port 0 dev 0000:01:00.0 slot 0 pin 1 
[    0.565093] ifx_pcie_bios_map_irq dev 0000:01:00.0 irq 144 assigned
[    0.571441] ifx_pcie_bios_map_irq port 0 dev 0000:02:00.0 slot 0 pin 1 
[    0.578103] ifx_pcie_bios_map_irq dev 0000:02:00.0 irq 144 assigned
[    0.585457] Switched to clocksource MIPS
[    0.625010] NET: Registered protocol family 2
[    0.630490] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.637376] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.643757] TCP: Hash tables configured (established 1024 bind 1024)
[    0.650311] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.656113] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.662814] NET: Registered protocol family 1
[    0.667204] PCI: CLS 0 bytes, default 32
[    0.667623] gptu: totally 6 16-bit timers/counters
[    0.672468] gptu: misc_register on minor 63
[    0.676560] gptu: succeeded to request irq 126
[    0.681042] gptu: succeeded to request irq 127
[    0.685558] gptu: succeeded to request irq 128
[    0.690070] gptu: succeeded to request irq 129
[    0.694583] gptu: succeeded to request irq 130
[    0.699097] gptu: succeeded to request irq 131
[    0.704572] phy-xrx200 gphy-xrx200: requesting lantiq/vr9_phy11g_a2x.bin
[    0.711904] phy-xrx200 gphy-xrx200: booting GPHY0 firmware at 7A80000
[    0.718232] phy-xrx200 gphy-xrx200: booting GPHY1 firmware at 7A80000
[    0.826197] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.842627] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.848374] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.860059] io scheduler noop registered
[    0.863909] io scheduler deadline registered (default)
[    0.869870] 1e100c00.serial: ttyLTQ0 at MMIO 0x1e100c00 (irq = 112, base_baud = 0) is a lantiq,asc
[    0.878766] console [ttyLTQ0] enabled
[    0.886097] bootconsole [early0] disabled
[    0.897878] nand: device found, Manufacturer ID: 0x01, Chip ID: 0xf1
[    0.902769] nand: AMD/Spansion S34ML01G1
[    0.906688] nand: 128 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    0.914327] Scanning device for bad blocks
[    0.940898] Bad eraseblock 155 at 0x000001360000
[    1.065750] Bad eraseblock 995 at 0x000007c60000
[    1.073013] 5 ofpart partitions found on MTD device 10000000.nand-parts
[    1.078202] Creating 5 MTD partitions on "10000000.nand-parts":
[    1.084119] 0x000000000000-0x000000040000 : "u-boot"
[    1.090310] 0x000000040000-0x000000080000 : "uboot-env"
[    1.095415] 0x000000080000-0x0000000a0000 : "caldata"
[    1.100463] 0x0000000a0000-0x0000002a0000 : "kernel"
[    1.105433] 0x0000002a0000-0x000008000000 : "ubi"
[    1.213708] libphy: lantiq,xrx200-mdio: probed
[    1.290188] eth0: attached PHY [Lantiq XWAY PEF7071] (phy_addr=0:00, irq=-1)
[    1.358163] eth0: attached PHY [Lantiq XWAY PEF7071] (phy_addr=0:01, irq=-1)
[    1.364054] eth0 (uninitialized): no PHY found
[    1.368216] xrx200-mdio: probing phy of port 2 failed
[    1.434148] eth0: attached PHY [Lantiq XWAY VR9 GPHY 11G v1.4] (phy_addr=0:13, irq=-1)
[    1.506171] eth1: attached PHY [Lantiq XWAY PEF7071] (phy_addr=0:05, irq=-1)
[    1.513183] wdt 1f8803f0.watchdog: Init done
[    1.519231] NET: Registered protocol family 10
[    1.527170] NET: Registered protocol family 17
[    1.530323] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
[    1.542850] 8021q: 802.1Q VLAN Support v1.8
[    1.550826] ath9k,eeprom ath9k_eep: pci slot: 14
[    1.554023] pci 0000:00:0e.0: fixup device configuration
[    1.560933] pci 0000:00:0e.0: fixup info: [168c:002d] revision 01 class 0x028000
[    1.566924] ath9k,eeprom ath9k_eep: loaded ath9k eeprom
[    1.575887] UBI: auto-attach mtd4
[    1.577635] ubi0: attaching mtd4
[    2.219011] ubi0: scanning is finished
[    2.260719] ubi0: attached mtd4 (name "ubi", size 125 MiB)
[    2.264813] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 129024 bytes
[    2.271650] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 512
[    2.278349] ubi0: VID header offset: 512 (aligned 512), data offset: 2048
[    2.285137] ubi0: good PEBs: 1001, bad PEBs: 2, corrupted PEBs: 0
[    2.291243] ubi0: user volume: 1, internal volumes: 1, max. volumes count: 128
[    2.298463] ubi0: max/mean erase counter: 5/1, WL threshold: 4096, image sequence number: 1453961604
[    2.307595] ubi0: available PEBs: 0, total reserved PEBs: 1001, PEBs reserved for bad PEB handling: 18
[    2.317916] ubi0: background thread "ubi_bgt0d" started, PID 246
[    2.428456] UBIFS (ubi0:0): background thread "ubifs_bgt0_0" started, PID 248
[    2.535115] UBIFS (ubi0:0): recovery needed
[    3.061052] UBIFS (ubi0:0): recovery completed
[    3.064223] UBIFS (ubi0:0): UBIFS: mounted UBI device 0, volume 0, name "rootfs"
[    3.071483] UBIFS (ubi0:0): LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    3.081389] UBIFS (ubi0:0): FS size: 124895232 bytes (119 MiB, 968 LEBs), journal size 9033728 bytes (8 MiB, 71 LEBs)
[    3.091999] UBIFS (ubi0:0): reserved for root: 0 bytes (0 KiB)
[    3.097841] UBIFS (ubi0:0): media format: w4/r0 (latest is w4/r0), UUID F6940B07-9C4C-4B1E-8309-2D2A067DE82D, small LPT model
[    3.110717] VFS: Mounted root (ubifs filesystem) on device 0:12.
[    3.116130] Freeing unused kernel memory: 256K (80550000 - 80590000)
[    3.464873] init: Console is alive
[    3.467167] init: - watchdog -
[    4.791936] SCSI subsystem initialized
[    4.858583] dwc2 1e101000.ifxhcd: requested GPIO 489
[    5.717650] dwc2 1e101000.ifxhcd: DWC OTG Controller
[    5.721223] dwc2 1e101000.ifxhcd: new USB bus registered, assigned bus number 1
[    5.728563] dwc2 1e101000.ifxhcd: irq 62, io mem 0x00000000
[    5.734089] dwc2 1e101000.ifxhcd: Hardware does not support descriptor DMA mode -
[    5.741526] dwc2 1e101000.ifxhcd: falling back to buffer DMA mode.
[    5.748981] hub 1-0:1.0: USB hub found
[    5.751987] hub 1-0:1.0: 1 port detected
[    6.481728] init: - preinit -
[    9.794052] random: procd urandom read with 37 bits of entropy available
[    9.892399] mount_root: mounting /dev/root
[    9.903974] mount_root: loading kmods from internal overlay
[   10.274246] block: attempting to load /etc/config/fstab
[   10.287072] block: extroot: not configured
[   10.301848] procd: - early -
[   10.303416] procd: - watchdog -
[   10.920419] procd: - ubus -
[   11.950794] procd: - init -
[   13.031657] IFXOS, Version 1.5.19 (c) Copyright 2009, Lantiq Deutschland GmbH
[   13.070803] NET: Registered protocol family 8
[   13.073776] NET: Registered protocol family 20
[   13.094453] tun: Universal TUN/TAP device driver, 1.6
[   13.098117] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[   13.125964] PPP generic driver version 2.4.2
[   13.148004] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   13.262940] Lantiq (VRX) DSL CPE MEI driver, version 1.4.8.4, (c) 2013 Lantiq Deutschland GmbH
[   13.262940] 
[   13.262940] Lantiq CPE API Driver version: DSL CPE API V4.16.2.4
[   13.380369] 
[   13.380369] Predefined debug level: 3
[   13.389787] Loading modules backported from Linux version master-2015-10-26-0-g28c26cb
[   13.396319] Backport generated by backports.git backports-20150903-4-g12cf266
[   13.687788] cfg80211: World regulatory domain updated:
[   13.691539] cfg80211:  DFS Master region: unset
[   13.695846] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   13.705603] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   13.713609] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   13.721616] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[   13.729627] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[   13.739115] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[   13.748599] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[   13.756693] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[   13.764701] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[   14.476124] PCI: Enabling device 0000:01:00.0 (0000 -> 0002)
[   14.480494] PCI: Enabling device 0000:02:00.0 (0000 -> 0002)
[   14.486591] ath10k_pci 0000:02:00.0: pci irq legacy interrupts 0 irq_mode 0 reset_mode 0
[   14.935801] ath10k_pci 0000:02:00.0: Direct firmware load for ath10k/QCA988X/hw2.0/board-2.bin failed with error -2
[   14.944860] ath10k_pci 0000:02:00.0: Falling back to user helper
[   15.002418] firmware ath10k!QCA988X!hw2.0!board-2.bin: firmware_loading_store: map pages failed
[   16.050744] ath10k_pci 0000:02:00.0: qca988x hw2.0 (0x4100016c, 0x043202ff sub 0000:0000) fw 10.2.4.70.12-2 fwapi 5 bdapi 1 htt-ver 2.1 wmi-op 5 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1 features no-p2p,raw-mode
[   16.068603] ath10k_pci 0000:02:00.0: debug 1 debugfs 1 tracing 1 dfs 1 testmode 1
[   16.165624] ath: EEPROM regdomain: 0x833a
[   16.165647] ath: EEPROM indicates we should expect a country code
[   16.165669] ath: doing EEPROM country->regdmn map search
[   16.165684] ath: country maps to regdmn code: 0x37
[   16.165697] ath: Country alpha2 being used: GB
[   16.165709] ath: Regpair used: 0x37
[   16.177930] cfg80211: Regulatory domain changed to country: GB
[   16.182381] cfg80211:  DFS Master region: ETSI
[   16.186599] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[   16.196362] cfg80211:   (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[   16.204367] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[   16.213853] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[   16.223339] cfg80211:   (5490000 KHz - 5710000 KHz @ 160000 KHz), (N/A, 2700 mBm), (0 s)
[   16.231432] cfg80211:   (57000000 KHz - 66000000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
[   16.569979] ip_tables: (C) 2000-2006 Netfilter Core Team
[   16.590642] Infineon Technologies DEU driver version 2.0.0 
[   16.596468] IFX DEU DES initialized (multiblock).
[   16.600781] IFX DEU AES initialized (multiblock).
[   16.604889] IFX DEU ARC4 initialized (multiblock).
[   16.609552] IFX DEU SHA1 initialized.
[   16.613038] IFX DEU MD5 initialized.
[   16.616702] IFX DEU SHA1_HMAC initialized.
[   16.620823] IFX DEU MD5_HMAC initialized.
[   16.668993] nf_conntrack version 0.5.0 (1939 buckets, 7756 max)
[   16.708762] NET: Registered protocol family 24
[   16.736864] xt_time: kernel timezone is -0000
[   16.868225] PCI: Enabling device 0000:00:0e.0 (0000 -> 0002)
[   16.878345] ath: phy1: Ignoring endianness difference in EEPROM magic bytes.
[   16.885788] ath: EEPROM regdomain: 0x833a
[   16.885808] ath: EEPROM indicates we should expect a country code
[   16.885830] ath: doing EEPROM country->regdmn map search
[   16.885845] ath: country maps to regdmn code: 0x37
[   16.885858] ath: Country alpha2 being used: GB
[   16.885869] ath: Regpair used: 0x37
[   16.903335] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[   16.906738] ieee80211 phy1: Atheros AR9287 Rev:2 mem=0xb8000000, irq=30
[   18.753538] random: nonblocking pool is initialized
[   21.717054] PTM 1.0.27    PTM (E1) firmware version 0.30
[   21.720981] ifxmips_ptm: PTM init succeed
[   24.573078] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   24.593518] device eth0.1 entered promiscuous mode
[   24.596863] device eth0 entered promiscuous mode
[   24.618126] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[   24.673649] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   25.109616] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   25.277654] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   26.277776] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   26.292445] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   26.428945] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   26.901625] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   27.069640] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   30.075485] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   30.106450] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   30.158378] device wlan0 entered promiscuous mode
[   30.229509] device wlan1 entered promiscuous mode
[   30.232932] br-lan: port 3(wlan1) entered forwarding state
[   30.238401] br-lan: port 3(wlan1) entered forwarding state
[   30.244756] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   31.077554] br-lan: port 3(wlan1) entered disabled state
[   31.549592] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   33.073687] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   33.078927] br-lan: port 2(wlan0) entered forwarding state
[   33.084222] br-lan: port 2(wlan0) entered forwarding state
[   34.369969] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   34.375173] br-lan: port 3(wlan1) entered forwarding state
[   34.380491] br-lan: port 3(wlan1) entered forwarding state
[   35.085527] br-lan: port 2(wlan0) entered forwarding state
[   36.381523] br-lan: port 3(wlan1) entered forwarding state
[   36.633779] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   41.817655] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   41.865683] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   42.018573] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   42.721586] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   42.865738] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   42.880439] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   43.329579] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   43.589584] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   47.037574] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   52.053575] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   57.205653] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   57.257680] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   57.407953] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   57.465579] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   58.257748] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   58.272444] /mnt/devel/openwrt/chaos_calmer/build_dir/target-mips_34kc+dsp_musl-1.1.11/linux-lantiq_xrx200/ltq-ptm-vr9/ifxmips_ptm_vdsl.c:281:ptm_hard_start_xmit: not in showtime
[   58.604995] enter showtime
[   58.609762] enter showtime
[   62.475148] pppoe-wan: renamed from ppp0
[13253.210885] nf_conntrack: automatic helper assignment is deprecated and it will be removed soon. Use the iptables CT target to attach helpers instead.
[204043.688507] ath10k_pci 0000:02:00.0: failed to install key for vdev 0 peer <mac address of ath10k device>: -145
[204043.696307] wlan0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-145)
[204046.700587] ath10k_pci 0000:02:00.0: failed to install key for vdev 0 peer <mac address of ath10k device>: -145
[204046.708417] wlan0: failed to set key (1, ff:ff:ff:ff:ff:ff) to hardware (-145)

5G wifi devices:
Nexus 5 (2013) - which is always connected/trying to connect
most of the time a QCA9558 device
and today I tried to connect with an Intel AC 7260 notebook (the QCA9558 device was off at this time)

comment:15 in reply to: ↑ 14 Changed 2 years ago by anonymous

Replying to anonymous:

most of the time a QCA9558 device
and today I tried to connect with an Intel AC 7260 notebook (the QCA9558 device was off at this time)

Sorry, instead of QCA9558 I meant QCA9880-2R4E:
ath10k_pci 0000:00:00.0: qca988x hw2.0 (0x4100016c, 0x043202ff) fw 10.2.4.45 api 4 htt 2.1 wmi 5 cal otp max_sta 128

comment:16 follow-up: Changed 2 years ago by anonymous

I am now using the firmware form r47984 for more than a week:
No problems so far (before that it broke every 1-3 days)!

From my point of view this is solved / can be closed.

comment:17 in reply to: ↑ 16 Changed 2 years ago by anonymous

Replying to anonymous:

I am now using the firmware form r47984 for more than a week:
No problems so far (before that it broke every 1-3 days)!

From my point of view this is solved / can be closed.

Same here, running 10.2.4.97 for 4 days without any problem.

comment:18 Changed 2 years ago by nbd

  • Resolution set to fixed
  • Status changed from reopened to closed

comment:19 Changed 21 months ago by gkelleter

I have to reopen this ticket because it is really far from resolved.

This bug happens on current OpenWrt master branch with different firmwares. (as of May 2016)
10.2.4.70-2
10.2.4.70.12-2
10.2.4.70.31-1
10.2.4.70.42-2
10.2.4.97-1

It always happens shortly after a GTK rekey.
The only difference between the firmwares is that it appears to happen sooner (after first GTK rekey, i.e 10min) or later (after 1 to 2 hours)

After these events the ath10k radio is dead. Must restart wifi to make it work again for the next 10 minutes), rinse and repeat.

Fri May 13 10:04:03 2016 daemon.info hostapd: wlan0-1: STA 78:7e:61:61:15:a3 WPA: group key handshake completed (RSN)
Fri May 13 10:06:57 2016 daemon.notice netifd: vlan1 (1179): Sending renew...
Fri May 13 10:06:57 2016 daemon.notice netifd: vlan1 (1179): Lease of 172.25.201.218 obtained, lease time 600
Fri May 13 10:11:57 2016 daemon.notice netifd: vlan1 (1179): Sending renew...
Fri May 13 10:11:57 2016 daemon.notice netifd: vlan1 (1179): Lease of 172.25.201.218 obtained, lease time 600
Fri May 13 10:14:01 2016 daemon.debug hostapd: wlan0: WPA rekeying GTK
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.666556] ath10k_pci 0000:00:00.0: failed to delete peer 78:7e:61:61:15:a3 for vdev 1: -145
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.675239] ------------[ cut here ]------------
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.680175] WARNING: CPU: 0 PID: 1367 at compat-wireless-2016-01-15/net/mac80211/sta_info.c:94
0 sta_set_sinfo+0x91c/0x9c8 [mac80211]()
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.692480] Modules linked in: iptable_nat ath9k nf_nat_ipv4 nf_conntrack_ipv6 nf_conntrack_ip
v4 ipt_REJECT ipt_MASQUERADE ebtable_nat ebtable_filter ebtable_broute ath9k_common xt_time xt_tcpudp xt_state xt_nat xt_multiport xt_mark x
t_mac xt_limit xt_id xt_conntrack xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_CT nf_reject_ipv4 nf_nat_redirect nf_nat_masquerade_ipv4 nf_nat
 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_rtcache nf_conntrack iptable_raw ipFri May 13 10:14:10 2016 kern.warn kernel: [71516
.766332] CPU: 0 PID: 1367 Comm: hostapd Not tainted 4.1.16 #11
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545] Stack : 8038eea0 00000000 00000001 803e0000 87a18780 803ce863 80371678 00000557
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545]         80433514 00000004 87b26000 00000000 00000000 800a6190 803ddec4 803d0000
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545]         00000003 00000004 80374f00 864c1b1c 00000000 800a47bc 878a5500 00000000
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545]         00000001 801e4400 00000000 00000000 00000000 00000000 00000000 00000000
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545]         00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.772545]         ...
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.809069] Call Trace:
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.811593] [<80071fdc>] show_stack+0x50/0x84
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.816060] [<8008158c>] warn_slowpath_common+0xa0/0xd0
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.821417] [<80081640>] warn_slowpath_null+0x18/0x24
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.826738] [<87186bd4>] sta_set_sinfo+0x91c/0x9c8 [mac80211]
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.832692] 
Fri May 13 10:14:10 2016 kern.warn kernel: [71516.834226] ---[ end trace a0c18c3aa915a062 ]---
Fri May 13 10:14:10 2016 daemon.info hostapd: wlan0-1: STA 78:7e:61:61:15:a3 IEEE 802.11: deauthenticated due to local deauth request
Fri May 13 10:14:13 2016 kern.warn kernel: [71519.846483] ath10k_pci 0000:00:00.0: failed to set dtim period for vdev 0: -11
Fri May 13 10:14:16 2016 kern.warn kernel: [71522.846434] ath10k_pci 0000:00:00.0: failed to recalculate rts/cts prot for vdev 0: -11
Fri May 13 10:14:19 2016 kern.warn kernel: [71525.846367] ath10k_pci 0000:00:00.0: failed to set protection mode 0 on vdev 0: -11
Fri May 13 10:14:22 2016 kern.warn kernel: [71528.846273] ath10k_pci 0000:00:00.0: failed to set preamble for vdev 0: -11
Fri May 13 10:14:25 2016 kern.warn kernel: [71531.856226] ath10k_pci 0000:00:00.0: failed to set beacon mode for vdev 1: -11
Fri May 13 10:14:28 2016 kern.warn kernel: [71534.856133] ath10k_pci 0000:00:00.0: failed to set dtim period for vdev 1: -11
Fri May 13 10:14:31 2016 kern.warn kernel: [71537.856068] ath10k_pci 0000:00:00.0: failed to recalculate rts/cts prot for vdev 1: -11
Fri May 13 10:14:34 2016 kern.warn kernel: [71540.856025] ath10k_pci 0000:00:00.0: failed to set protection mode 0 on vdev 1: -11
Fri May 13 10:14:37 2016 kern.warn kernel: [71543.855952] ath10k_pci 0000:00:00.0: failed to set preamble for vdev 1: -11
Fri May 13 10:16:57 2016 daemon.notice netifd: vlan1 (1179): Sending renew...
Fri May 13 10:16:57 2016 daemon.notice netifd: vlan1 (1179): Lease of 172.25.201.218 obtained, lease time 600
Fri May 13 10:21:57 2016 daemon.notice netifd: vlan1 (1179): Sending renew...
Fri May 13 10:21:57 2016 daemon.notice netifd: vlan1 (1179): Lease of 172.25.201.218 obtained, lease time 600
Fri May 13 10:24:01 2016 daemon.debug hostapd: wlan0: WPA rekeying GTK
Fri May 13 10:24:04 2016 kern.warn kernel: [72110.902760] ath10k_pci 0000:00:00.0: failed to install key for vdev 0 peer f4:06:8d:38:59:75: 
-11
Fri May 13 10:24:04 2016 kern.err kernel: [72110.911806] wlan0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-11)
Fri May 13 10:24:07 2016 kern.warn kernel: [72113.912691] ath10k_pci 0000:00:00.0: failed to install key for vdev 0 peer f4:06:8d:38:59:75: 
-11
Fri May 13 10:24:07 2016 kern.err kernel: [72113.921740] wlan0: failed to set key (1, ff:ff:ff:ff:ff:ff) to hardware (-11)
Fri May 13 10:24:10 2016 kern.warn kernel: [72116.932618] ath10k_pci 0000:00:00.0: failed to install key for vdev 1 peer f6:06:8d:38:59:75: 
-11
Fri May 13 10:24:10 2016 kern.err kernel: [72116.941663] wlan0-1: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-11)
Fri May 13 10:24:13 2016 kern.warn kernel: [72119.942550] ath10k_pci 0000:00:00.0: failed to install key for vdev 1 peer f6:06:8d:38:59:75: 
-11
Fri May 13 10:24:13 2016 kern.err kernel: [72119.951597] wlan0-1: failed to set key (1, ff:ff:ff:ff:ff:ff) to hardware (-11)

(edit: I pasted the wrong log from a Chaos Calmer revision)

Last edited 21 months ago by gkelleter (previous) (diff)

comment:20 Changed 21 months ago by gkelleter

  • Resolution fixed deleted
  • Status changed from closed to reopened

Add Comment

Modify Ticket

Action
as reopened .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.