From nobody@FreeBSD.org Thu Dec 15 17:03:18 2011 Return-Path: Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 90AAA106566C for ; Thu, 15 Dec 2011 17:03:18 +0000 (UTC) (envelope-from nobody@FreeBSD.org) Received: from red.freebsd.org (red.freebsd.org [IPv6:2001:4f8:fff6::22]) by mx1.freebsd.org (Postfix) with ESMTP id 8007E8FC16 for ; Thu, 15 Dec 2011 17:03:18 +0000 (UTC) Received: from red.freebsd.org (localhost [127.0.0.1]) by red.freebsd.org (8.14.4/8.14.4) with ESMTP id pBFH3IMg011446 for ; Thu, 15 Dec 2011 17:03:18 GMT (envelope-from nobody@red.freebsd.org) Received: (from nobody@localhost) by red.freebsd.org (8.14.4/8.14.4/Submit) id pBFH3ION011442; Thu, 15 Dec 2011 17:03:18 GMT (envelope-from nobody) Message-Id: <201112151703.pBFH3ION011442@red.freebsd.org> Date: Thu, 15 Dec 2011 17:03:18 GMT From: Joel Dahl To: freebsd-gnats-submit@FreeBSD.org Subject: ath(4) stops working X-Send-Pr-Version: www-3.1 X-GNATS-Notify: >Number: 163318 >Category: kern >Synopsis: [ath] ath(4) stops working >Confidential: no >Severity: non-critical >Priority: low >Responsible: freebsd-wireless >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Thu Dec 15 17:10:03 UTC 2011 >Closed-Date: >Last-Modified: Wed Jan 18 22:30:06 UTC 2012 >Originator: Joel Dahl >Release: 10.0-CURRENT >Organization: N/A >Environment: FreeBSD crashbox.vnode.se 10.0-CURRENT FreeBSD 10.0-CURRENT #0: Wed Dec 14 20:11:58 CET 2011 joel@crashbox.vnode.se:/usr/obj/usr/src/sys/GENERIC amd64 >Description: I bought a wireless PCI card for my desktop machine a couple of days ago, it is identified as: joel@crashbox [~] dmesg | grep -i ath ath0: mem 0xf0600000-0xf060ffff irq 20 at device 0.0 on pci16 ath0: Enabling register serialisation ath0: AR9220 mac 128.2 RF5133 phy 13.0 joel@crashbox [~] pciconf -bclv ath0@pci0:16:0:0: class=0x028000 card=0x3a7c1186 chip=0x0029168c rev=0x01 hdr=0x00 vendor = 'Atheros Communications Inc.' device = 'AR922X Wireless Network Adapter' class = network bar [10] = type Memory, range 32, base 0xf0600000, size 65536, enabled cap 01[44] = powerspec 2 supports D0 D3 current D0 I've noticed that somewhere around 4 hours of uptime it stops working. I just get no route to host while trying to ping something. I've played around with ifconfig and the wlan0 interface but rebooting seems to be my only option in order to get it working again. I have compiled my kernel with: options ATH_DEBUG options AH_DEBUG options ATH_DIAGAPI On the console I see the following, but these messages stops as soon as ath stops working: Dec 14 21:29:05 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 14 22:29:04 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 14 22:29:09 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 14 23:29:09 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 14 23:29:14 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 14 23:55:24 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 15 00:55:22 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 15 01:55:24 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 15 01:55:29 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Running tcpdump -ni wlan0 -y IEEE802_11_RADIO after ath has died produces no output. I see the following on the console however: wlan0: promiscuous mode enabled wlan0: promiscuous mode disabled wlan0: promiscuous mode enabled taskqueue_drain with the following non-sleepable locks held: exclusive sleep mutex bpf global lock (bpf global lock) r = 0 (0xffffffff8133f6a0) locked @ /usr/src/sys/net/bpf.c:651 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 _witness_debugger() at _witness_debugger+0x2c witness_warn() at witness_warn+0x2c6 taskqueue_drain() at taskqueue_drain+0xfd ieee80211_waitfor_parent() at ieee80211_waitfor_parent+0x2b ieee80211_ioctl() at ieee80211_ioctl+0x161 if_setflag() at if_setflag+0x111 ifpromisc() at ifpromisc+0x34 bpf_detachd() at bpf_detachd+0x1c6 bpf_dtor() at bpf_dtor+0x8d devfs_destroy_cdevpriv() at devfs_destroy_cdevpriv+0x8b devfs_close_f() at devfs_close_f+0x54 _fdrop() at _fdrop+0x23 closef() at closef+0x5c kern_close() at kern_close+0x121 amd64_syscall() at amd64_syscall+0x3ac Xfast_syscall() at Xfast_syscall+0xf7 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8011c899c, rsp = 0x7fffffffd258, rbp = 0x801807300 --- taskqueue_drain with the following non-sleepable locks held: exclusive sleep mutex bpf global lock (bpf global lock) r = 0 (0xffffffff8133f6a0) locked @ /usr/src/sys/net/bpf.c:651 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 _witness_debugger() at _witness_debugger+0x2c witness_warn() at witness_warn+0x2c6 taskqueue_drain() at taskqueue_drain+0xfd ieee80211_waitfor_parent() at ieee80211_waitfor_parent+0x3e ieee80211_ioctl() at ieee80211_ioctl+0x161 if_setflag() at if_setflag+0x111 ifpromisc() at ifpromisc+0x34 bpf_detachd() at bpf_detachd+0x1c6 bpf_dtor() at bpf_dtor+0x8d devfs_destroy_cdevpriv() at devfs_destroy_cdevpriv+0x8b devfs_close_f() at devfs_close_f+0x54 _fdrop() at _fdrop+0x23 closef() at closef+0x5c kern_close() at kern_close+0x121 amd64_syscall() at amd64_syscall+0x3ac Xfast_syscall() at Xfast_syscall+0xf7 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8011c899c, rsp = 0x7fffffffd258, rbp = 0x801807300 --- taskqueue_drain with the following non-sleepable locks held: exclusive sleep mutex bpf global lock (bpf global lock) r = 0 (0xffffffff8133f6a0) locked @ /usr/src/sys/net/bpf.c:651 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 _witness_debugger() at _witness_debugger+0x2c witness_warn() at witness_warn+0x2c6 taskqueue_drain() at taskqueue_drain+0xfd ieee80211_waitfor_parent() at ieee80211_waitfor_parent+0x51 ieee80211_ioctl() at ieee80211_ioctl+0x161 if_setflag() at if_setflag+0x111 ifpromisc() at ifpromisc+0x34 bpf_detachd() at bpf_detachd+0x1c6 bpf_dtor() at bpf_dtor+0x8d devfs_destroy_cdevpriv() at devfs_destroy_cdevpriv+0x8b devfs_close_f() at devfs_close_f+0x54 _fdrop() at _fdrop+0x23 closef() at closef+0x5c kern_close() at kern_close+0x121 amd64_syscall() at amd64_syscall+0x3ac Xfast_syscall() at Xfast_syscall+0xf7 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8011c899c, rsp = 0x7fffffffd258, rbp = 0x801807300 --- taskqueue_drain with the following non-sleepable locks held: exclusive sleep mutex bpf global lock (bpf global lock) r = 0 (0xffffffff8133f6a0) locked @ /usr/src/sys/net/bpf.c:651 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 _witness_debugger() at _witness_debugger+0x2c witness_warn() at witness_warn+0x2c6 taskqueue_drain() at taskqueue_drain+0xfd ieee80211_waitfor_parent() at ieee80211_waitfor_parent+0x64 ieee80211_ioctl() at ieee80211_ioctl+0x161 if_setflag() at if_setflag+0x111 ifpromisc() at ifpromisc+0x34 bpf_detachd() at bpf_detachd+0x1c6 bpf_dtor() at bpf_dtor+0x8d devfs_destroy_cdevpriv() at devfs_destroy_cdevpriv+0x8b devfs_close_f() at devfs_close_f+0x54 _fdrop() at _fdrop+0x23 closef() at closef+0x5c kern_close() at kern_close+0x121 amd64_syscall() at amd64_syscall+0x3ac Xfast_syscall() at Xfast_syscall+0xf7 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8011c899c, rsp = 0x7fffffffd258, rbp = 0x801807300 --- taskqueue_drain with the following non-sleepable locks held: exclusive sleep mutex bpf global lock (bpf global lock) r = 0 (0xffffffff8133f6a0) locked @ /usr/src/sys/net/bpf.c:651 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a kdb_backtrace() at kdb_backtrace+0x37 _witness_debugger() at _witness_debugger+0x2c witness_warn() at witness_warn+0x2c6 taskqueue_drain() at taskqueue_drain+0xfd ieee80211_waitfor_parent() at ieee80211_waitfor_parent+0x77 ieee80211_ioctl() at ieee80211_ioctl+0x161 if_setflag() at if_setflag+0x111 ifpromisc() at ifpromisc+0x34 bpf_detachd() at bpf_detachd+0x1c6 bpf_dtor() at bpf_dtor+0x8d devfs_destroy_cdevpriv() at devfs_destroy_cdevpriv+0x8b devfs_close_f() at devfs_close_f+0x54 _fdrop() at _fdrop+0x23 closef() at closef+0x5c kern_close() at kern_close+0x121 amd64_syscall() at amd64_syscall+0x3ac Xfast_syscall() at Xfast_syscall+0xf7 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8011c899c, rsp = 0x7fffffffd258, rbp = 0x801807300 --- wlan0: promiscuous mode disabled ..and when I reboot, I just briefly can see the following message fly by on the console before the machine reboots: ath0: ath_tx_tid_drain: node 0xffffff80014a2000: tid 16: txq_depth=2, txq_aggr_depth=0, sched=0, paused=0, hwq_depth=0, incomp=0, baw_head=0, baw_tail=0 txa_stat=-1, ni_txseqs=1966 This message is not shown if I reboot while ath is still working. >How-To-Repeat: >Fix: >Release-Note: >Audit-Trail: Responsible-Changed-From-To: freebsd-bugs->freebsd-wireless Responsible-Changed-By: linimon Responsible-Changed-When: Fri Dec 16 07:58:36 UTC 2011 Responsible-Changed-Why: Over to maintainer(s). http://www.freebsd.org/cgi/query-pr.cgi?pr=163318 From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Sat, 17 Dec 2011 00:09:02 +0100 I left the machine for a few hours again and when I came back I noticed the following messages on the console (wireless died as usual): Dec 16 17:26:31 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 17:26:36 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 17:43:54 crashbox kernel: ar5416PerCalibrationN: NF calibration didn't finish; delaying CCA Dec 16 18:26:38 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 18:26:42 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 18:49:24 crashbox kernel: ar5416PerCalibrationN: NF calibration didn't finish; delaying CCA Dec 16 19:26:42 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 19:29:50 crashbox kernel: ath0: device timeout Dec 16 19:29:50 crashbox kernel: ath0: ath_raw_xmit: sc_inreset_cnt > 0; bailing Dec 16 19:29:50 crashbox kernel: ath0: ath_chan_set: danger! concurrent reset! Dec 16 19:29:50 crashbox kernel: ath0: ath_tx_tid_drain: node 0xffffff80014a2000: tid 0: txq_depth=0, txq_aggr_depth=0, sched=1, paused=0, hwq_depth=0, incomp=0, baw_head=0, baw_tail=0 txa_start=0, ni_txseqs=15229 Dec 16 19:29:50 crashbox kernel: ath0: ath_start: sc_inreset_cnt > 0; bailing Dec 16 20:26:42 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 20:26:46 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 16 21:26:45 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Sun, 18 Dec 2011 17:35:18 +0100 Disabling bgscan with ifconfig wlan0 -bgscan fixes the problem. The machine has been running for 9 hours now without any problems. -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Sat, 24 Dec 2011 09:05:11 +0100 dding more information with the results from a private email conversation between me and adrian@: This is in station mode. It's a very simple setup, the only thing I've really configured is the following in rc.conf: wlans_ath0="wlan0" ifconfig_wlan0="WPA DHCP" And i've created the wpa_supplicant.conf file. ifconfig wlan0 says the following: root@crashbox [~] ifconfig wlan0 wlan0: flags=8843 metric 0 mtu 1500 ether 1c:7e:e5:10:5a:5d inet 10.10.10.238 netmask 0xffffff00 broadcast 10.10.10.255 nd6 options=29 media: IEEE 802.11 Wireless Ethernet OFDM/54Mbps mode 11g status: associated ssid DAHL channel 1 (2412 MHz 11g) bssid f8:1e:df:fc:34:2b regdomain ETSI indoor ecm authmode WPA2/802.11i privacy ON deftxkey UNDEF AES-CCM 3:128-bit txpower 20 bmiss 7 scanvalid 450 bgscan bgscanintvl 300 bgscanidle 250 roam:rssi 7 roam:rate 5 protmode CTS wme burst roaming MANUAL wlandebug +11n +input +output +rate and some pings from/to the unit: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 562 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 563 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 564 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 565 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 566 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 567 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 568 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 569 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 570 (size 50) no tx bufs (empty list): 0 no tx bufs (was busy): 0 aggr single packet: 0 aggr single packet w/ BAW closed: 0 aggr non-baw packet: 0 aggr aggregate packet: 0 aggr single packet low hwq: 0 aggr sched, no work: 0 0: 0 1: 0 2: 0 3: 0 4: 0 5: 0 6: 0 7: 0 8: 0 9: 0 10: 0 11: 0 12: 0 13: 0 14: 0 15: 0 16: 0 17: 0 18: 0 19: 0 20: 0 21: 0 22: 0 23: 0 24: 0 25: 0 26: 0 27: 0 28: 0 29: 0 30: 0 31: 0 32: 0 33: 0 34: 0 35: 0 36: 0 37: 0 38: 0 39: 0 40: 0 41: 0 42: 0 43: 0 44: 0 45: 0 46: 0 47: 0 48: 0 49: 0 50: 0 51: 0 52: 0 53: 0 54: 0 55: 0 56: 0 57: 0 58: 0 59: 0 60: 0 61: 0 62: 0 63: 0 HW TXQ 0: axq_depth=0, axq_aggr_depth=0 HW TXQ 1: axq_depth=2, axq_aggr_depth=0 HW TXQ 2: axq_depth=0, axq_aggr_depth=0 HW TXQ 3: axq_depth=0, axq_aggr_depth=0 HW TXQ 8: axq_depth=0, axq_aggr_depth=0 Total TX buffers: 198; Total TX buffers busy: 0 no tx bufs (empty list): 0 no tx bufs (was busy): 0 aggr single packet: 0 aggr single packet w/ BAW closed: 0 aggr non-baw packet: 0 aggr aggregate packet: 0 aggr single packet low hwq: 0 aggr sched, no work: 0 0: 0 1: 0 2: 0 3: 0 4: 0 5: 0 6: 0 7: 0 8: 0 9: 0 10: 0 11: 0 12: 0 13: 0 14: 0 15: 0 16: 0 17: 0 18: 0 19: 0 20: 0 21: 0 22: 0 23: 0 24: 0 25: 0 26: 0 27: 0 28: 0 29: 0 30: 0 31: 0 32: 0 33: 0 34: 0 35: 0 36: 0 37: 0 38: 0 39: 0 40: 0 41: 0 42: 0 43: 0 44: 0 45: 0 46: 0 47: 0 48: 0 49: 0 50: 0 51: 0 52: 0 53: 0 54: 0 55: 0 56: 0 57: 0 58: 0 59: 0 60: 0 61: 0 62: 0 63: 0 HW TXQ 0: axq_depth=0, axq_aggr_depth=0 HW TXQ 1: axq_depth=2, axq_aggr_depth=0 HW TXQ 2: axq_depth=0, axq_aggr_depth=0 HW TXQ 3: axq_depth=0, axq_aggr_depth=0 HW TXQ 8: axq_depth=0, axq_aggr_depth=0 Total TX buffers: 198; Total TX buffers busy: 0 no tx bufs (empty list): 0 no tx bufs (was busy): 0 aggr single packet: 0 aggr single packet w/ BAW closed: 0 aggr non-baw packet: 0 aggr aggregate packet: 0 aggr single packet low hwq: 0 aggr sched, no work: 0 0: 0 1: 0 2: 0 3: 0 4: 0 5: 0 6: 0 7: 0 8: 0 9: 0 10: 0 11: 0 12: 0 13: 0 14: 0 15: 0 16: 0 17: 0 18: 0 19: 0 20: 0 21: 0 22: 0 23: 0 24: 0 25: 0 26: 0 27: 0 28: 0 29: 0 30: 0 31: 0 32: 0 33: 0 34: 0 35: 0 36: 0 37: 0 38: 0 39: 0 40: 0 41: 0 42: 0 43: 0 44: 0 45: 0 46: 0 47: 0 48: 0 49: 0 50: 0 51: 0 52: 0 53: 0 54: 0 55: 0 56: 0 57: 0 58: 0 59: 0 60: 0 61: 0 62: 0 63: 0 HW TXQ 0: axq_depth=0, axq_aggr_depth=0 HW TXQ 1: axq_depth=2, axq_aggr_depth=0 HW TXQ 2: axq_depth=0, axq_aggr_depth=0 HW TXQ 3: axq_depth=0, axq_aggr_depth=0 HW TXQ 8: axq_depth=0, axq_aggr_depth=0 Total TX buffers: 198; Total TX buffers busy: 0 no tx bufs (empty list): 0 no tx bufs (was busy): 0 aggr single packet: 0 aggr single packet w/ BAW closed: 0 aggr non-baw packet: 0 aggr aggregate packet: 0 aggr single packet low hwq: 0 aggr sched, no work: 0 0: 0 1: 0 2: 0 3: 0 4: 0 5: 0 6: 0 7: 0 8: 0 9: 0 10: 0 11: 0 12: 0 13: 0 14: 0 15: 0 16: 0 17: 0 18: 0 19: 0 20: 0 21: 0 22: 0 23: 0 24: 0 25: 0 26: 0 27: 0 28: 0 29: 0 30: 0 31: 0 32: 0 33: 0 34: 0 35: 0 36: 0 37: 0 38: 0 39: 0 40: 0 41: 0 42: 0 43: 0 44: 0 45: 0 46: 0 47: 0 48: 0 49: 0 50: 0 51: 0 52: 0 53: 0 54: 0 55: 0 56: 0 57: 0 58: 0 59: 0 60: 0 61: 0 62: 0 63: 0 HW TXQ 0: axq_depth=0, axq_aggr_depth=0 HW TXQ 1: axq_depth=2, axq_aggr_depth=0 HW TXQ 2: axq_depth=0, axq_aggr_depth=0 HW TXQ 3: axq_depth=0, axq_aggr_depth=0 HW TXQ 8: axq_depth=0, axq_aggr_depth=0 Total TX buffers: 198; Total TX buffers busy: 0 wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 571 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 572 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 573 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 574 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 575 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 576 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 577 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 578 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 579 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 580 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 581 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 582 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 583 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 584 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 585 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 586 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 587 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 588 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 589 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 590 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 591 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 592 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 593 (size 50) wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 594 (size 50) Later on, tried doing: wlandebug 0 wlandebug +input +output +rate ping 10.10.10.255 (broadcast ping) The only thing that appear in dmesg after setting the above and doing a broadcast ping is: Dec 24 06:07:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 171 (size 50) Dec 24 06:08:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 172 (size 50) Dec 24 06:08:22 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 173 (size 50) Dec 24 06:08:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 174 (size 50) Dec 24 06:13:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 175 (size 50) Dec 24 06:13:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 176 (size 50) Dec 24 06:14:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 177 (size 50) Dec 24 06:14:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 178 (size 50) Dec 24 06:14:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 179 (size 50) Dec 24 06:14:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 180 (size 50) Dec 24 06:19:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 181 (size 50) Dec 24 06:19:54 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 182 (size 50) Dec 24 06:20:05 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 183 (size 50) Dec 24 06:20:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 184 (size 50) Dec 24 06:20:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 185 (size 50) Dec 24 06:25:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 186 (size 50) Dec 24 06:25:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 187 (size 50) Dec 24 06:25:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 188 (size 50) Dec 24 06:26:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 189 (size 50) Dec 24 06:26:19 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 190 (size 50) Dec 24 06:26:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 191 (size 50) Dec 24 06:31:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 192 (size 50) Dec 24 06:31:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 193 (size 50) Dec 24 06:32:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 194 (size 50) Dec 24 06:32:22 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 195 (size 50) Dec 24 06:32:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 196 (size 50) Dec 24 06:37:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 197 (size 50) Dec 24 06:37:57 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 198 (size 50) Dec 24 06:38:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 199 (size 50) Dec 24 06:38:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 200 (size 50) Dec 24 06:38:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 201 (size 50) FWIW, I rebooted the machine and immediately turned on the wlandebug stuff above (while ath was still working). ath died a few hours later as usual, and the above "pwr save q overflow" messages started appearing in dmesg almost right away. -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 28 Dec 2011 09:05:11 +0100 Some more information after chatting with adrian@: I'm not running powerd or anything like that. Wireless stops working after 3 to 5 hours of uptime. Dec 26 16:18:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:18:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:23:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:23:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:28:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:28:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:33:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:33:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:38:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:38:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:43:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:43:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:48:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:48:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:53:17 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 26 16:53:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:53:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 16:58:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 16:58:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:03:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:03:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:08:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:08:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:13:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:14:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:19:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:19:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:24:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:24:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:29:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:29:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:34:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:34:10 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:39:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:39:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:44:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:44:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:49:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:49:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:53:16 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 26 17:54:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:54:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 17:59:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 17:59:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:04:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:04:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:09:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:09:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:14:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:14:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:19:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:19:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:24:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:24:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:29:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:29:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:34:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:34:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:39:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:39:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:44:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:44:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:49:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:49:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:53:16 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Dec 26 18:54:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:54:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:59:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:59:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 40, 1 now queued Dec 26 18:59:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 2 now queued Dec 26 18:59:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 18:59:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] flush ps queue, 2 packets queued Dec 26 18:59:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 18:59:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:04:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:04:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:09:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:09:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:14:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:15:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:20:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:20:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:25:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:25:05 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:30:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:30:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:35:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:35:10 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:40:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 19:40:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Dec 26 19:45:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Dec 26 20:03:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 40, 1 now queued Dec 26 20:03:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 2 now queued Dec 26 20:03:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 3 now queued Dec 26 20:03:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 4 now queued Dec 26 20:04:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 5 now queued Dec 26 20:04:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 6 now queued Dec 26 20:05:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 7 now queued Dec 26 20:05:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 8 now queued Dec 26 20:05:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 9 now queued Dec 26 20:05:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 10 now queued Dec 26 20:06:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 11 now queued Dec 26 20:06:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 12 now queued Dec 26 20:06:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 13 now queued Dec 26 20:06:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 14 now queued Dec 26 20:07:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 15 now queued Dec 26 20:08:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 16 now queued Dec 26 20:08:57 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 17 now queued Dec 26 20:09:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 18 now queued Dec 26 20:09:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 19 now queued Dec 26 20:10:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 20 now queued Dec 26 20:11:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 21 now queued Dec 26 20:11:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 22 now queued Dec 26 20:11:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 23 now queued Dec 26 20:11:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 24 now queued Dec 26 20:12:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 25 now queued Dec 26 20:12:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 26 now queued Dec 26 20:13:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 27 now queued Dec 26 20:13:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 28 now queued Dec 26 20:14:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 29 now queued Dec 26 20:15:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 30 now queued Dec 26 20:16:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 31 now queued Dec 26 20:17:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 32 now queued Dec 26 20:18:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 33 now queued Dec 26 20:18:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 34 now queued Dec 26 20:18:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 35 now queued Dec 26 20:18:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 36 now queued Dec 26 20:18:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 37 now queued Dec 26 20:18:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 38 now queued Dec 26 20:19:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 39 now queued Dec 26 20:20:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 40 now queued Dec 26 20:22:19 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 41 now queued Dec 26 20:24:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 42 now queued Dec 26 20:27:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 43 now queued Dec 26 20:31:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 44 now queued Dec 26 20:33:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 45 now queued Dec 26 20:33:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 46 now queued Dec 26 20:33:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 47 now queued Dec 26 20:33:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 48 now queued Dec 26 20:33:57 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 49 now queued Dec 26 20:34:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 50 now queued Dec 26 20:34:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 1 (size 50) Dec 26 20:39:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 2 (size 50) Dec 26 20:39:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 3 (size 50) Dec 26 20:39:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 4 (size 50) Dec 26 20:39:55 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 5 (size 50) Dec 26 20:40:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 6 (size 50) Dec 26 20:40:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 7 (size 50) Dec 26 20:45:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 8 (size 50) Dec 26 20:45:37 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 9 (size 50) Dec 26 20:45:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 10 (size 50) Dec 26 20:45:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 11 (size 50) Dec 26 20:46:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 12 (size 50) Dec 26 20:46:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 13 (size 50) Dec 26 20:51:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 14 (size 50) Dec 26 20:51:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 15 (size 50) Dec 26 20:51:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 16 (size 50) Dec 26 20:51:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 17 (size 50) Dec 26 20:52:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 18 (size 50) Dec 26 20:52:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 19 (size 50) Dec 26 20:57:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 20 (size 50) Dec 26 20:57:42 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 21 (size 50) Dec 26 20:57:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 22 (size 50) Dec 26 20:58:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 23 (size 50) Dec 26 20:58:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 24 (size 50) Dec 26 21:03:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 25 (size 50) Dec 26 21:03:42 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 26 (size 50) Dec 26 21:03:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 27 (size 50) Dec 26 21:04:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 28 (size 50) Dec 26 21:04:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 29 (size 50) Dec 26 21:04:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 30 (size 50) Dec 26 21:09:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 31 (size 50) Dec 26 21:09:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 32 (size 50) Dec 26 21:09:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 33 (size 50) Dec 26 21:10:02 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 34 (size 50) Dec 26 21:10:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 35 (size 50) Dec 26 21:15:37 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 36 (size 50) Dec 26 21:15:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 37 (size 50) Dec 26 21:15:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 38 (size 50) Dec 26 21:16:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 39 (size 50) Dec 26 21:16:27 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 40 (size 50) Dec 26 21:21:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 41 (size 50) Dec 26 21:21:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 42 (size 50) Dec 26 21:21:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 43 (size 50) Dec 26 21:22:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 44 (size 50) Dec 26 21:22:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 45 (size 50) -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 28 Dec 2011 09:20:21 +0100 ...and some more info: Wireless survives if "wlandebug +state +scan +power" is set. Wireless dies as usual if "wlandebug +state +power" is set. -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 4 Jan 2012 08:18:46 +0100 This is the output in /var/log messages when running wlandebug +state +power (it dies as usual after a few hours). Output starts from right after the machine has been booted. Jan 3 17:27:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:27:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:32:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:32:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:37:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:37:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:42:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:42:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:43:37 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 17:47:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:47:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:52:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:52:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 17:57:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 17:57:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:02:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:02:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:07:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:07:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:12:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:12:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:17:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:17:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:22:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:22:54 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:27:54 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:27:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:32:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:32:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:37:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:38:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:43:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:43:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:43:36 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 18:48:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:48:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:53:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:53:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 18:58:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 18:58:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:03:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:03:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:08:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:08:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:13:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:13:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:18:19 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:18:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:23:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:23:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:28:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:28:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:33:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:33:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:38:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:38:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:43:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:43:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:43:36 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 19:48:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:48:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:53:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:53:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 19:58:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 19:58:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:03:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:03:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:08:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:08:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:13:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:13:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:18:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:18:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:23:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:23:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:28:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:28:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:33:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:33:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:38:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:39:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:43:37 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 20:44:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:44:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:49:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:49:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:54:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:54:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 20:59:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 20:59:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:04:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:04:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:09:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:09:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:14:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:14:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:19:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:19:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:24:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:24:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:29:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:29:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:33:39 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 21:34:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:34:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:39:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:39:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:44:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:44:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:49:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:49:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:54:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:54:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 21:59:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 21:59:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:04:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:04:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:09:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:09:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:14:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:14:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:19:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:19:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:24:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:24:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:29:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:29:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:33:39 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 22:34:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:34:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:39:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:40:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:45:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:45:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:50:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:50:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 22:55:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 22:55:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 23:00:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 23:00:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 23:03:09 crashbox wpa_supplicant[473]: WPA: Group rekeying completed with f8:1e:df:fc:34:2b [GTK=CCMP] Jan 3 23:05:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 23:05:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 3 23:10:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 3 23:22:27 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 40, 1 now queued Jan 3 23:22:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 2 now queued Jan 3 23:22:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 3 now queued Jan 3 23:22:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 4 now queued Jan 3 23:23:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 5 now queued Jan 3 23:23:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 6 now queued Jan 3 23:23:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 7 now queued Jan 3 23:23:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 8 now queued Jan 3 23:23:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 9 now queued Jan 3 23:23:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 10 now queued Jan 3 23:24:05 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 11 now queued Jan 3 23:24:22 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 12 now queued Jan 3 23:24:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 13 now queued Jan 3 23:25:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 14 now queued Jan 3 23:25:10 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 15 now queued Jan 3 23:25:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 16 now queued Jan 3 23:26:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 17 now queued Jan 3 23:26:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 18 now queued Jan 3 23:26:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 19 now queued Jan 3 23:27:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 20 now queued Jan 3 23:27:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 21 now queued Jan 3 23:28:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 22 now queued Jan 3 23:29:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 23 now queued Jan 3 23:29:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 24 now queued Jan 3 23:30:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 25 now queued Jan 3 23:30:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 26 now queued Jan 3 23:30:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 27 now queued Jan 3 23:30:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 28 now queued Jan 3 23:31:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 29 now queued Jan 3 23:31:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 30 now queued Jan 3 23:31:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 31 now queued Jan 3 23:32:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 32 now queued Jan 3 23:33:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 33 now queued Jan 3 23:35:02 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 34 now queued Jan 3 23:36:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 35 now queued Jan 3 23:37:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 36 now queued Jan 3 23:37:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 37 now queued Jan 3 23:37:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 38 now queued Jan 3 23:38:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 39 now queued Jan 3 23:38:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 40 now queued Jan 3 23:38:37 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 41 now queued Jan 3 23:38:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 42 now queued Jan 3 23:39:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 43 now queued Jan 3 23:39:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 44 now queued Jan 3 23:39:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 45 now queued Jan 3 23:39:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 46 now queued Jan 3 23:39:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 47 now queued Jan 3 23:40:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 48 now queued Jan 3 23:40:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 49 now queued Jan 3 23:40:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 50 now queued Jan 3 23:41:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 1 (size 50) Jan 3 23:41:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 2 (size 50) Jan 3 23:42:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 3 (size 50) Jan 3 23:44:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 4 (size 50) Jan 3 23:44:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 5 (size 50) Jan 3 23:45:55 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 6 (size 50) Jan 3 23:47:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 7 (size 50) Jan 3 23:48:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 8 (size 50) Jan 3 23:51:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 9 (size 50) Jan 3 23:52:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 10 (size 50) Jan 3 23:52:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 11 (size 50) Jan 3 23:52:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 12 (size 50) Jan 3 23:52:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 13 (size 50) Jan 3 23:53:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 14 (size 50) Jan 3 23:53:17 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 15 (size 50) Jan 3 23:58:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 16 (size 50) Jan 3 23:58:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 17 (size 50) Jan 3 23:58:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 18 (size 50) Jan 3 23:59:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 19 (size 50) Jan 3 23:59:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 20 (size 50) Jan 4 00:04:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 21 (size 50) Jan 4 00:04:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 22 (size 50) Jan 4 00:04:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 23 (size 50) Jan 4 00:04:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 24 (size 50) Jan 4 00:05:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 25 (size 50) Jan 4 00:05:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 26 (size 50) Jan 4 00:10:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 27 (size 50) Jan 4 00:10:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 28 (size 50) Jan 4 00:10:42 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 29 (size 50) Jan 4 00:10:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 30 (size 50) Jan 4 00:11:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 31 (size 50) Jan 4 00:11:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 32 (size 50) Jan 4 00:16:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 33 (size 50) Jan 4 00:16:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 34 (size 50) Jan 4 00:16:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 35 (size 50) Jan 4 00:16:55 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 36 (size 50) Jan 4 00:17:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 37 (size 50) Jan 4 00:17:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 38 (size 50) Jan 4 00:22:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 39 (size 50) Jan 4 00:22:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 40 (size 50) Jan 4 00:22:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 41 (size 50) Jan 4 00:23:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 42 (size 50) Jan 4 00:23:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 43 (size 50) Jan 4 00:23:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 44 (size 50) Jan 4 00:28:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 45 (size 50) Jan 4 00:28:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 46 (size 50) Jan 4 00:28:55 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 47 (size 50) Jan 4 00:29:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 48 (size 50) Jan 4 00:29:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 49 (size 50) Jan 4 00:29:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 50 (size 50) One more thing, when I rebooted the machine after ath(4) stopped working the following messages quickly flashed by on the screen while it was shutting down: wlan0: [f8:1e:df:fc:34:2b] station deauth via MLME (reason 3) wlan0: ieee80211_new_state_locked: RUN -> INIT (nrunning 0 nscanning 0) wlan0: ieee80211_newstate_cb: RUN -> INIT arg 3 wlan0: sta_newstate: RUN -> INIT (3) ath0: ath_tx_tid_drain: node 0xffffff80014a2000: tid 16: txq_depth=2, txq_aggr_depth=0, sched=0, paused=0, hwq_depth=0, incomp=0, baw_head=0, baw_tail=0 txa_stat=-1, ni_txseqs=1782 wlan0: [f8:1e:df:fc:34:2b] power save mode off, 0 sta's in ps mode wlan0: link state changed to DOWN wlan0: stop running, 1 vaps running wlan0: ieee80211_new_state_locked: RUN -> INIT (nrunning 0 nscanning 0) wlan0: down parent ath0 wlan0: ieee80211_newstate_cb: INIT -> INIT arg -1 wlan0: sta_newstate: INIT -> INIT (-1) wlan0: sta_newstate: unexpected state transition INIT -> INIT It looks like it managed come out of power save mode again? -- Joel From: Adrian Chadd To: bug-followup@FreeBSD.org, joel@FreeBSD.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 4 Jan 2012 18:34:39 -0800 Hi, Please try this patch: Index: sys/net80211/ieee80211_power.c =================================================================== --- sys/net80211/ieee80211_power.c (revision 228893) +++ sys/net80211/ieee80211_power.c (working copy) @@ -504,8 +504,13 @@ { struct ieee80211_node *ni = vap->iv_bss; - if (!((enable != 0) ^ ((ni->ni_flags & IEEE80211_NODE_PWR_MGT) != 0))) + if (!((enable != 0) ^ + ((ni->ni_flags & IEEE80211_NODE_PWR_MGT) != 0))) { + IEEE80211_NOTE(vap, IEEE80211_MSG_POWER, ni, + "sta power save mode %s ignored", + enable ? "on" : "off"); return; + } IEEE80211_NOTE(vap, IEEE80211_MSG_POWER, ni, "sta power save mode %s", enable ? "on" : "off"); .. then just enable wlandebug +power. I'd like to see whether the station power management enable is being ignored for some reason. Adrian From: Joel Dahl To: Adrian Chadd Cc: bug-followup@FreeBSD.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Fri, 6 Jan 2012 18:44:56 +0100 I've tried your patch now, but it didn't trigger any new messages. Output looks like this (it only took about 30 minutes after boot before it stopped working this time, must be a new record...): Jan 6 17:28:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:29:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 17:34:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:34:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 17:39:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:39:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 17:44:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:44:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 17:49:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:49:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 17:54:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode on Jan 6 17:57:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 40, 1 now queued Jan 6 17:57:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 2 now queued Jan 6 17:57:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 3 now queued Jan 6 17:57:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 4 now queued Jan 6 18:15:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 5 now queued Jan 6 18:15:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 6 now queued Jan 6 18:15:37 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 7 now queued Jan 6 18:16:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 8 now queued Jan 6 18:17:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 9 now queued Jan 6 18:17:05 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 10 now queued Jan 6 18:17:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 11 now queued Jan 6 18:17:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 12 now queued Jan 6 18:17:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 13 now queued Jan 6 18:17:26 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 14 now queued Jan 6 18:17:27 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 15 now queued Jan 6 18:17:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 16 now queued Jan 6 18:17:29 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 17 now queued Jan 6 18:17:30 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 18 now queued Jan 6 18:17:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 19 now queued Jan 6 18:17:32 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 20 now queued Jan 6 18:17:33 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 21 now queued Jan 6 18:17:34 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 22 now queued Jan 6 18:17:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 23 now queued Jan 6 18:17:36 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 24 now queued Jan 6 18:17:37 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 25 now queued Jan 6 18:17:38 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 26 now queued Jan 6 18:17:39 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 27 now queued Jan 6 18:17:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 28 now queued Jan 6 18:17:41 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 29 now queued Jan 6 18:17:42 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 30 now queued Jan 6 18:17:43 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 31 now queued Jan 6 18:17:44 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 32 now queued Jan 6 18:17:45 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 33 now queued Jan 6 18:17:46 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 34 now queued Jan 6 18:17:47 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 35 now queued Jan 6 18:17:48 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 36 now queued Jan 6 18:17:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 37 now queued Jan 6 18:17:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 38 now queued Jan 6 18:17:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 39 now queued Jan 6 18:17:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 40 now queued Jan 6 18:17:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 41 now queued Jan 6 18:21:02 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 42 now queued Jan 6 18:21:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 43 now queued Jan 6 18:21:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 44 now queued Jan 6 18:21:10 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 45 now queued Jan 6 18:21:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 46 now queued Jan 6 18:21:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 47 now queued Jan 6 18:21:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 48 now queued Jan 6 18:21:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 49 now queued Jan 6 18:21:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] save frame with age 0, 50 now queued Jan 6 18:21:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 1 (size 50) Jan 6 18:21:17 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 2 (size 50) Jan 6 18:21:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 3 (size 50) Jan 6 18:21:19 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 4 (size 50) Jan 6 18:21:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 5 (size 50) Jan 6 18:21:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 6 (size 50) Jan 6 18:21:22 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 7 (size 50) Jan 6 18:21:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 8 (size 50) Jan 6 18:21:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 9 (size 50) Jan 6 18:21:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 10 (size 50) Jan 6 18:23:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 11 (size 50) Jan 6 18:24:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 12 (size 50) Jan 6 18:24:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 13 (size 50) Jan 6 18:24:17 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 14 (size 50) Jan 6 18:24:27 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 15 (size 50) Jan 6 18:24:40 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 16 (size 50) Jan 6 18:24:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 17 (size 50) Jan 6 18:25:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 18 (size 50) Jan 6 18:26:35 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 19 (size 50) Jan 6 18:26:49 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 20 (size 50) Jan 6 18:26:50 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 21 (size 50) Jan 6 18:26:51 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 22 (size 50) Jan 6 18:26:52 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 23 (size 50) Jan 6 18:26:53 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 24 (size 50) Jan 6 18:26:54 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 25 (size 50) Jan 6 18:26:55 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 26 (size 50) Jan 6 18:26:56 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 27 (size 50) Jan 6 18:26:57 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 28 (size 50) Jan 6 18:26:58 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 29 (size 50) Jan 6 18:26:59 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 30 (size 50) Jan 6 18:27:00 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 31 (size 50) Jan 6 18:27:01 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 32 (size 50) Jan 6 18:27:02 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 33 (size 50) Jan 6 18:27:03 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 34 (size 50) Jan 6 18:27:04 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 35 (size 50) Jan 6 18:27:05 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 36 (size 50) Jan 6 18:27:06 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 37 (size 50) Jan 6 18:27:07 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 38 (size 50) Jan 6 18:27:08 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 39 (size 50) Jan 6 18:27:09 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 40 (size 50) Jan 6 18:27:10 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 41 (size 50) Jan 6 18:27:11 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 42 (size 50) Jan 6 18:27:12 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 43 (size 50) Jan 6 18:27:13 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 44 (size 50) Jan 6 18:27:14 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 45 (size 50) Jan 6 18:27:15 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 46 (size 50) Jan 6 18:27:16 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 47 (size 50) Jan 6 18:27:17 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 48 (size 50) Jan 6 18:27:18 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 49 (size 50) Jan 6 18:27:19 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 50 (size 50) Jan 6 18:27:20 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 51 (size 50) Jan 6 18:27:21 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 52 (size 50) Jan 6 18:27:22 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 53 (size 50) Jan 6 18:27:23 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 54 (size 50) Jan 6 18:27:24 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 55 (size 50) However, here I did a "ifconfig wlan0 scan", and got these messages: Jan 6 18:27:25 crashbox wpa_supplicant[475]: CTRL-EVENT-DISCONNECTED bssid=f8:1e:df:fc:34:2b reason=0 Jan 6 18:27:25 crashbox kernel: ath0: ath_tx_tid_drain: node 0xffffff80014a2000: tid 16: txq_depth=0, txq_aggr_depth=0, sched=1, paused=0, hwq_depth=0, incomp=0, baw_head=0, baw_tail=0 txa_start=-1, ni_txseqs=137 Jan 6 18:27:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] pwr save q overflow, drops 56 (size 50) Jan 6 18:27:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off Jan 6 18:27:25 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] flush ps queue, 50 packets queued Jan 6 18:27:25 crashbox kernel: ath0: ath_tx_tid_drain: node 0xffffff80014a2000: tid 0: txq_depth=37, txq_aggr_depth=0, sched=0, paused=0, hwq_depth=36, incomp=0, baw_head=0, baw_tail=0 txa_start=0, ni_txseqs=189 Jan 6 18:27:25 crashbox kernel: wlan0: link state changed to DOWN Jan 6 18:27:28 crashbox wpa_supplicant[475]: Trying to associate with f8:1e:df:fc:34:2b (SSID='DAHL' freq=2412 MHz) Jan 6 18:27:28 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off ignored Jan 6 18:27:28 crashbox kernel: wlan0: link state changed to UP Jan 6 18:27:28 crashbox wpa_supplicant[475]: Associated with 00:00:00:00:00:00 Jan 6 18:27:28 crashbox kernel: wlan0: link state changed to DOWN Jan 6 18:27:28 crashbox wpa_supplicant[475]: CTRL-EVENT-DISCONNECTED bssid=f8:1e:df:fc:34:2b reason=0 Jan 6 18:27:30 crashbox kernel: wlan0: ieee80211_new_state_locked: pending ASSOC -> AUTH transition lost Jan 6 18:27:30 crashbox last message repeated 3 times Jan 6 18:27:31 crashbox wpa_supplicant[475]: Trying to associate with f8:1e:df:fc:34:2b (SSID='DAHL' freq=2412 MHz) Jan 6 18:27:31 crashbox kernel: wlan0: [f8:1e:df:fc:34:2b] sta power save mode off ignored Jan 6 18:27:31 crashbox wpa_supplicant[475]: Associated with f8:1e:df:fc:34:2b Jan 6 18:27:31 crashbox kernel: wlan0: link state changed to UP Jan 6 18:27:31 crashbox wpa_supplicant[475]: WPA: Key negotiation completed with f8:1e:df:fc:34:2b [PTK=CCMP GTK=CCMP] Jan 6 18:27:31 crashbox wpa_supplicant[475]: CTRL-EVENT-CONNECTED - Connection to f8:1e:df:fc:34:2b completed (reauth) [id=0 id_str=] Jan 6 18:27:38 crashbox dhclient: New IP Address (wlan0): 10.10.10.238 Jan 6 18:27:38 crashbox dhclient: New Subnet Mask (wlan0): 255.255.255.0 Jan 6 18:27:38 crashbox dhclient: New Broadcast Address (wlan0): 10.10.10.255 Jan 6 18:27:38 crashbox dhclient: New Routers (wlan0): 10.10.10.1 ...and it's working again. So, "ifconfig wlan0 scan" seems to be an easy way to get it working again after it has died. -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Sat, 7 Jan 2012 09:37:17 +0100 Some more information: Adrian requested that I set the following sysctl in order to collect more debugging information: wlandebug +state +power sysctl dev.ath.0.debug=0x00040000 However, wireless never stops working once the above is set, so it's hard to get any useful information. The machine has 1 CPU, with 2 cores. The NIC is PCI. The exact model of the NIC is: D-Link RangeBooster N 650 Desktop Adapter DWA-547 -- Joel From: Joel Dahl To: bug-followup@freebsd.org Cc: Subject: Re: kern/163318: [ath] ath(4) stops working Date: Tue, 10 Jan 2012 18:50:37 +0100 For the record: I put in another PCI ath(4) card and I'm seeing the same thing with this card. After a while, wireless stops working. It seems to go in to some power save mode, and then gets stuck. ifconfig wlan0 scan fixes it, as usual. One thing I've noticed though is that it seems to take much longer for this card to stop working. Usually around 9-10 hours. Could be a coincidence of course. This card is identified as: joel@crashbox [~] dmesg | grep ath ath0: mem 0xf0600000-0xf060ffff irq 20 at device 0.0 on pci16 ath0: AR2413 mac 7.9 RF2413 phy 4.5 ath0: 2GHz radio: 0x0000; 5GHz radio: 0x0056 ath0@pci0:16:0:0: class=0x020000 card=0x3a131186 chip=0x0013168c rev=0x01 hdr=0x00 vendor = 'Atheros Communications Inc.' device = 'Atheros AR5001X+ Wireless Network Adapter' class = network subclass = ethernet bar [10] = type Memory, range 32, base 0xf0600000, size 65536, enabled cap 01[44] = powerspec 2 supports D0 D3 current D0 -- Joel From: Adrian Chadd To: Joel Dahl Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Sun, 15 Jan 2012 12:10:02 -0800 Hi, So I want to establish whether the scan logic has hung, or whether the scan logic has completed but left the interface hung. How's your C? Would you mind doing some quick hacking: * add a new variable in struct ath_softc, call it "sc_in_scan"; * set it to 1 in ath_scan_start (don't add any locks) * set it to 0 in ath_scan_end (don't add any locks) * edit the 'txagg' sysctl code in if_ath_sysctl.c to print out the value of sc_in_scan; Then verify that it's working as advertised: * sysctl dev.ath.0.txagg=1 and check dmesg - sc_in_scan should be 0; * do a manual scan (ifconfig wlan0 scan) and then redo the above sysctl - it should be 1. The "normal" scan will keep the interface in "scan" mode for the duration of all channel checks. But for bgscan, it quickly brings the interface in and out of scan mode, for each channel that's being scanned. What i hope to see is: * sc_in_scan stays 0 during normal operation; * when your interface is hung, sc_in_scan is 1. Once we've established that, we can continue to go digging into the scan code. Thanks! Adrian From: Joel Dahl To: Adrian Chadd Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Tue, 17 Jan 2012 19:50:57 +0100 On 15-01-2012 12:10, Adrian Chadd wrote: > Hi, > > So I want to establish whether the scan logic has hung, or whether the > scan logic has completed but left the interface hung. > > How's your C? Would you mind doing some quick hacking: > > * add a new variable in struct ath_softc, call it "sc_in_scan"; > * set it to 1 in ath_scan_start (don't add any locks) > * set it to 0 in ath_scan_end (don't add any locks) > * edit the 'txagg' sysctl code in if_ath_sysctl.c to print out the > value of sc_in_scan; > > Then verify that it's working as advertised: > > * sysctl dev.ath.0.txagg=1 and check dmesg - sc_in_scan should be 0; > * do a manual scan (ifconfig wlan0 scan) and then redo the above > sysctl - it should be 1. Hm. I did the above changes and rebuilt my kernel. If I do sysctl dev.ath0.txagg=1, sc_in_scan is 0 just as expected. If I do a manual scan right after, it is still set to 0. ...or was I supposed to _only_ do ifconfig wlan0 scan once the interface has died? -- Joel From: Adrian Chadd To: Joel Dahl Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Tue, 17 Jan 2012 10:53:42 -0800 On 17 January 2012 10:50, Joel Dahl wrote: >> Then verify that it's working as advertised: >> >> * sysctl dev.ath.0.txagg=1 and check dmesg - sc_in_scan should be 0; >> * do a manual scan (ifconfig wlan0 scan) and then redo the above >> sysctl - it should be 1. > > Hm. I did the above changes and rebuilt my kernel. If I do sysctl > dev.ath0.txagg=1, sc_in_scan is 0 just as expected. If I do a manual scan > right after, it is still set to 0. right. Can you check the sc_in_scan value _during_ an ifconfig wlan0 scan ? (ie, whilst it's running.) You'll have to be ninja-fast. I just want to verify that it's actually working.. > ...or was I supposed to _only_ do ifconfig wlan0 scan once the interface has > died? The above is just to verify that it's working. Once that's done, check sc_in_scan once the interface has hung. I'm testing the hypothesis that the scan logic is "hung" somehow and that is why the interface never comes out of STA power save mode. Adrian From: Joel Dahl To: Adrian Chadd Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Tue, 17 Jan 2012 21:56:16 +0100 On 17-01-2012 10:53, Adrian Chadd wrote: > On 17 January 2012 10:50, Joel Dahl wrote: > >> Then verify that it's working as advertised: > >> > >> * sysctl dev.ath.0.txagg=1 and check dmesg - sc_in_scan should be 0; > >> * do a manual scan (ifconfig wlan0 scan) and then redo the above > >> sysctl - it should be 1. > > > > Hm. I did the above changes and rebuilt my kernel. If I do sysctl > > dev.ath0.txagg=1, sc_in_scan is 0 just as expected. If I do a manual scan > > right after, it is still set to 0. > > right. Can you check the sc_in_scan value _during_ an ifconfig wlan0 > scan ? (ie, whilst it's running.) > > You'll have to be ninja-fast. > > I just want to verify that it's actually working.. Yes, it's set to 1 for a very short period during the scan. So it seems to work like it should. > > ...or was I supposed to _only_ do ifconfig wlan0 scan once the interface has > > died? > > The above is just to verify that it's working. Once that's done, check > sc_in_scan once the interface has hung. > > I'm testing the hypothesis that the scan logic is "hung" somehow and > that is why the interface never comes out of STA power save mode. I'll check this next. -- Joel From: Joel Dahl To: adrian.chadd@gmail.com Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 18 Jan 2012 06:40:07 +0100 I left the machine on during the night and when I came back the interface had hung as usual. So I checked the output from sysctl dev.ath.0.txagg=1 but sc_in_scan is still 0... -- Joel From: Joel Dahl To: Adrian Chadd Cc: bug-followup@freebsd.org Subject: Re: kern/163318: [ath] ath(4) stops working Date: Wed, 18 Jan 2012 23:27:48 +0100 I can't even remember if I've reported this before, but when ath died a couple of minutes ago I got this in dmesg: ath0: device timeout ath0: ath_reset_grablock: didn't finish after 10 iterations ath0: ath_reset_grablock: warning, recursive reset path! ath0: ath_chan_set: concurrent reset! Danger! Just FYI, -- Joel >Unformatted: