Comment 1 Mark Linimon 2011-12-16 07:58:36 UTC

Responsible Changed
From-To: freebsd-bugs->freebsd-wireless

Over to maintainer(s).

Comment 2 Joel Dahl 2011-12-16 23:09:02 UTC

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

Comment 3 Joel Dahl 2011-12-18 16:35:18 UTC

Disabling bgscan with

  ifconfig wlan0 -bgscan

fixes the problem. The machine has been running for 9 hours now without any
problems.

-- 
Joel

Comment 4 Joel Dahl 2011-12-24 08:05:11 UTC

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<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> 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<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>
  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

Comment 5 Joel Dahl 2011-12-28 08:05:11 UTC

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.

<Machine is booted and wlandebug +power is set ...>

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

<wireless stops working here ...>

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

Comment 6 Joel Dahl 2011-12-28 08:20:21 UTC

...and some more info:

Wireless survives if "wlandebug +state +scan +power" is set.

Wireless dies as usual if "wlandebug +state +power" is set.

-- 
Joel

Comment 7 Joel Dahl 2012-01-04 07:18:46 UTC

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

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

Comment 9 Joel Dahl 2012-01-06 17:44:56 UTC

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

Comment 10 Joel Dahl 2012-01-07 08:37:17 UTC

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

Comment 11 Joel Dahl 2012-01-10 17:50:37 UTC

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: <Atheros 5212> 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 rxf0600000, size 65536, enabled
    cap 01[44] = powerspec 2  supports D0 D3  current D0

-- 
Joel

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

Comment 13 Joel Dahl 2012-01-17 18:50:57 UTC

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

On 17 January 2012 10:50, Joel Dahl <joel@freebsd.org> 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

Comment 15 Joel Dahl 2012-01-17 20:56:16 UTC

On 17-01-2012 10:53, Adrian Chadd wrote:
> On 17 January 2012 10:50, Joel Dahl <joel@freebsd.org> 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

Comment 16 Joel Dahl 2012-01-18 05:40:07 UTC

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

Comment 17 Joel Dahl 2012-01-18 22:27:48 UTC

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

Hi Joel,

I've been exploring this a little further.

I wonder if the actual bg scan task is stuck - even though scan
start/end is being called correctly inside scan_task(), I wonder if
something is trampling over the flags at the same time and causing
scan_task() to think another scan is coming, but never does.

A bgscan should be occuring every X seconds though. So I wonder why it
wouldn't next be running.

So would you mind plugging it back in and having it fail, then once it does:

wlandebug +power +scan

And then let's see if it actually _does_ try to do background scanning
once it's hung. I hope it prints something useful about why it isn't
running.

Thanks,


adrian

Hi,

Please try this patch.



Adrian

Comment 20 dfilter service 2012-03-02 02:53:55 UTC

Author: adrian
Date: Fri Mar  2 02:53:43 2012
New Revision: 232373
URL: http://svn.freebsd.org/changeset/base/232373

Log:
  Attempt to catch scan cancellations at exactly the wrong time from occuring.
  
  The scan code unlocks the comlock and calls into the driver.  It then
  assumes the state hasn't changed from underneath it.
  
  Although I haven't seen this particular condition trigger, I'd like to
  be informed if I or anyone else sees it.
  
  What I'm thinking may occur:
  
  * A cancellation comes in during the scan_end call;
  * the cancel flag is set;
  * but it's never checked, so scandone isn't updated;
  * .. and the interface stays in the STA power save mode.
  
  It's a subtle race, if it even exists.
  
  PR:		kern/163318

Modified:
  head/sys/net80211/ieee80211_scan.c

Modified: head/sys/net80211/ieee80211_scan.c
==============================================================================
--- head/sys/net80211/ieee80211_scan.c	Fri Mar  2 00:21:07 2012	(r232372)
+++ head/sys/net80211/ieee80211_scan.c	Fri Mar  2 02:53:43 2012	(r232373)
@@ -960,6 +960,19 @@ scan_task(void *arg, int pending)
 	IEEE80211_LOCK(ic);
 
 	/*
+	 * Since a cancellation may have occured during one of the
+	 * driver calls (whilst unlocked), update scandone.
+	 */
+	if (scandone == 0 &&
+	    ((SCAN_PRIVATE(ss)->ss_iflags & ISCAN_CANCEL) != 0)) {
+		/* XXX printf? */
+		if_printf(vap->iv_ifp,
+		    "%s: OOPS! scan cancelled during driver call!\n",
+		    __func__);
+	}
+	scandone |= ((SCAN_PRIVATE(ss)->ss_iflags & ISCAN_CANCEL) != 0);
+
+	/*
 	 * Record scan complete time.  Note that we also do
 	 * this when canceled so any background scan will
 	 * not be restarted for a while.
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscribe@freebsd.org"

Comment 21 dfilter service 2012-03-02 03:12:06 UTC

Author: adrian
Date: Fri Mar  2 03:11:53 2012
New Revision: 232375
URL: http://svn.freebsd.org/changeset/base/232375

Log:
  Wrap another ATH_LOCK around the scanning flag.
  
  PR:		kern/163318

Modified:
  head/sys/dev/ath/if_ath.c

Modified: head/sys/dev/ath/if_ath.c
==============================================================================
--- head/sys/dev/ath/if_ath.c	Fri Mar  2 02:57:10 2012	(r232374)
+++ head/sys/dev/ath/if_ath.c	Fri Mar  2 03:11:53 2012	(r232375)
@@ -5690,8 +5690,10 @@ ath_set_channel(struct ieee80211com *ic)
 	 * beacon timers.  Note that since we only hear beacons in
 	 * sta/ibss mode this has no effect in other operating modes.
 	 */
+	ATH_LOCK(sc);
 	if (!sc->sc_scanning && ic->ic_curchan == ic->ic_bsschan)
 		sc->sc_syncbeacon = 1;
+	ATH_UNLOCK(sc);
 }
 
 /*
_______________________________________________
svn-src-all@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-all
To unsubscribe, send any mail to "svn-src-all-unsubscribe@freebsd.org"

Comment 22 Joel Dahl 2012-03-11 20:01:00 UTC

Some news...

I updated from a Jan 18 CURRENT to a Feb 19 CURRENT some time ago and the
issue was gone. Adrian asked me to try to track down the revision that fixed
the problem, and that's what I've been doing for the last two weeks.

So I've been doing a binary search in order to nail the specific revision
that fixed my issues with ath. The problem usually occur after 6-8 hours of
uptime, but sometimes 30 minutes is enough. I've tested each revision twice.
If it survived 12 hours of uptime, I rebooted the machine and let it run for
another 12 hours just to be sure that each the revision really was OK. Same
goes for revisions that dies - each time ath died I rebooted the machine in
order to be sure that I could reproduce the problem again.

Revision 231852 does not survive for very long. It dies as usual. I haven't
been able to make any revision before 231852 survive longer than 8 hours.

Revision 231854 has survived my 12 hour testing period 3 times and I haven't
been able to crash any revision after 231854.

Adrian, your commit to the ath driver (231854) seems to fix my ath problems.
Does that make sense to you?

-- 
Joel

Hi!

On 11 March 2012 13:01, Joel Dahl <joel@freebsd.org> wrote:
> Some news...
>
> I updated from a Jan 18 CURRENT to a Feb 19 CURRENT some time ago and the
> issue was gone. Adrian asked me to try to track down the revision that fixed
> the problem, and that's what I've been doing for the last two weeks.

Sweet!


> Revision 231852 does not survive for very long. It dies as usual. I haven't
> been able to make any revision before 231852 survive longer than 8 hours.
>
> Revision 231854 has survived my 12 hour testing period 3 times and I haven't
> been able to crash any revision after 231854.
>
> Adrian, your commit to the ath driver (231854) seems to fix my ath problems.
> Does that make sense to you?

Nope. That just started shifting around locks. Can you please try
231852 with the debugging patch I threw you (that patched
ieee80211_scan.c) and see if it complains?

If that patch fixed anything, it just delayed things enough to hide
what's going on...


Adrian

Comment 24 Joel Dahl 2012-03-11 20:13:46 UTC

On 11-03-2012 13:07, Adrian Chadd wrote:
> Hi!
> 
> On 11 March 2012 13:01, Joel Dahl <joel@freebsd.org> wrote:
> > Some news...
> >
> > I updated from a Jan 18 CURRENT to a Feb 19 CURRENT some time ago and the
> > issue was gone. Adrian asked me to try to track down the revision that fixed
> > the problem, and that's what I've been doing for the last two weeks.
> 
> Sweet!
> 
> 
> > Revision 231852 does not survive for very long. It dies as usual. I haven't
> > been able to make any revision before 231852 survive longer than 8 hours.
> >
> > Revision 231854 has survived my 12 hour testing period 3 times and I haven't
> > been able to crash any revision after 231854.
> >
> > Adrian, your commit to the ath driver (231854) seems to fix my ath problems.
> > Does that make sense to you?
> 
> Nope. That just started shifting around locks. Can you please try
> 231852 with the debugging patch I threw you (that patched
> ieee80211_scan.c) and see if it complains?

Sure, I'll try 231852 + your patch.

> If that patch fixed anything, it just delayed things enough to hide
> what's going on...

I see. Hiding a problem is not equal to fixing it. :-)


-- 
Joel

On 11 March 2012 13:13, Joel Dahl <joel@freebsd.org> wrote:

>> Nope. That just started shifting around locks. Can you please try
>> 231852 with the debugging patch I threw you (that patched
>> ieee80211_scan.c) and see if it complains?
>
> Sure, I'll try 231852 + your patch.
>
>> If that patch fixed anything, it just delayed things enough to hide
>> what's going on...
>
> I see. Hiding a problem is not equal to fixing it. :-)

Yup. The main thing that changed is the order of the TX/RX/interrupt
taskqueue stop versus grabbing the PCU lock.

Since the PCU lock is also grabbed when doing some other things
(notably RX and interrupts, briefly in each situation), it's possible
that we're just now not hitting whatever the race is, versus having
fixed it.

I'd really like to know where the race _is_...


Adrian

Comment 26 Joel Dahl 2012-03-12 05:44:12 UTC

On 11-03-2012 13:45, Adrian Chadd wrote:
> On 11 March 2012 13:13, Joel Dahl <joel@freebsd.org> wrote:
> 
> >> Nope. That just started shifting around locks. Can you please try
> >> 231852 with the debugging patch I threw you (that patched
> >> ieee80211_scan.c) and see if it complains?
> >
> > Sure, I'll try 231852 + your patch.
> >
> >> If that patch fixed anything, it just delayed things enough to hide
> >> what's going on...
> >
> > I see. Hiding a problem is not equal to fixing it. :-)
> 
> Yup. The main thing that changed is the order of the TX/RX/interrupt
> taskqueue stop versus grabbing the PCU lock.
> 
> Since the PCU lock is also grabbed when doing some other things
> (notably RX and interrupts, briefly in each situation), it's possible
> that we're just now not hitting whatever the race is, versus having
> fixed it.
> 
> I'd really like to know where the race _is_...

231852 + your patch died after 2 hours, so the problem remains.

-- 
Joel

Comment 27 Eitan Adler 2018-05-28 19:42:52 UTC

batch change:

For bugs that match the following
-  Status Is In progress 
AND
- Untouched since 2018-01-01.
AND
- Affects Base System OR Documentation

DO:

Reset to open status.


Note:
I did a quick pass but if you are getting this email it might be worthwhile to double check to see if this bug ought to be closed.