2009-12-22 02:23:56

by Luis R. Rodriguez

Subject: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

I'm testing ath9k on an Asus eeepc 1008HA on a 2.6.32.2 kernel
and ran into a suspend corner case issue which we do not handle
yet. From what I've debugged so far it appears to me ath9k is
doing everything it should to suspend. mac80211 drivers don't
really do much on suspend except listen to mac80211. In the
suspend case the mac80211 first stops TX, flushes out all packets,
tears down aggregation, removes peers (if STA this would be your
AP), removes all interfaces and finally call the mac80211 driver
stop() callback for the driver. The driver is expected to have
completed the stop() successfully, it shall not fail. It should
be noted we never disassociate from the AP, this is left to
userspace to figure out if it wants to do this prior to suspend.
Network manger does this, for example. If you run the supplicant
manually though and if your AP does not kick you off you could
end up suspending and resumeing and still have a valid auth/assoc
to the AP.

Upon resume mac80211 first calls the mac80211 start() driver callback,
then re-add the interfaces, then the peers (your AP), etc. The corner
case I just ran into was that the mac80211 driver start() callback
*can* fail if your bus is screwy. You would likely see other sorts
of errors when this sort of thing happens but I'm not and when we
try to start() on ath9k we fail as the harware is completely
unresponsive. What ends up happening then currently is the driver
will enable interrupts and obviously though since we cannot even
reset the hardware these interrupts will have gone unhandled and
the interrupt gets disabled by the kernel. I reproduced this on
vanilla 2.6.32.2 but I only did get full ath9k debug logs when
testing against 2.6.31 with 2.6.32.2 wireless bits. That log can
be found here:

http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt

This can be fixed by something like the following:

diff --git a/net/mac80211/util.c b/net/mac80211/util.c
index e6c08da..63d42fa 100644
--- a/net/mac80211/util.c
+++ b/net/mac80211/util.c
@@ -1031,7 +1031,14 @@ int ieee80211_reconfig(struct ieee80211_local *local)

/* restart hardware */
if (local->open_count) {
+ /*
+ * Upon resume hardware can sometimes be goofy due to
+ * various platform issues, so restarting the device may
+ * at times not work immediately. Propagate the error.
+ */
res = drv_start(local);
+ if (res)
+ return res;

ieee80211_led_radio(local, true);
}

But this isn't enough. And since we cannot exactly talk to hardware
we can't try to send a deassoc as harware would be unresponsive. I
also don't see us handling such cases before either on cfg80211 or
mac80211, so curious what we should do. Doing the above is not enough
since userspace will still believe it will be associated if it left
the device in an associated state. If you end up killing userspace
and restarting you'll end up with crawling into cfg80211/mac80211
warnings due to the unexpected state we left things in. This is
currently busted on 2.6.32.2 and I don't see an obvious fix, hoping
others might.

As for the specific Asus eeepc 1008HA issue what I'm seeing is ath9k
talking to harware fine prior to suspend, disabling harware and then
upon resume it becomes unusable, failing at the first harware reset.
lspci tells me the following when the device is functional, both during
initial boot, and during successfull pm-suspend cycles:

01:00.0 Network controller: Atheros Communications Inc. AR9285 Wireless Network Adapter (PCI-Express) (rev 01)
Subsystem: Device 1a3b:1089
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 32 bytes
Interrupt: pin A routed to IRQ 18
Region 0: Memory at fbef0000 (64-bit, non-prefetchable) [size=64K]
Capabilities: [40] Power Management version 3
Flags: PMEClk- DSI- D1+ D2- AuxCurrent=375mA PME(D0+,D1+,D2-,D3hot+,D3cold+)
Status: D0 PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [50] Message Signalled Interrupts: Mask- 64bit- Queue=0/0 Enable-
Address: 00000000 Data: 0000
Capabilities: [60] Express (v2) Legacy Endpoint, MSI 00
DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 <64us
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
ClockPM- Suprise- LLActRep- BwNot-
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
Capabilities: [100] Advanced Error Reporting <?>
Capabilities: [140] Virtual Channel <?>
Capabilities: [160] Device Serial Number 12-14-24-ff-ff-17-15-00
Capabilities: [170] Power Budgeting <?>
Kernel driver in use: ath9k
Kernel modules: ath9k

I do notice a difference when resume goes bust and the ath9k device becomes unhappy. This
is what I see:

--- lspci-ok.txt 2009-12-21 17:22:24.000000000 -0800
+++ lspci-busted.txt 2009-12-21 17:22:50.000000000 -0800
@@ -16,7 +16,7 @@
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 512 bytes
- DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
+ DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
ClockPM- Suprise- LLActRep- BwNot-
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+

The line in question is the PCI device status. The CorrErr indicates
"Correctable Error Detected" and the UnsuppReq indicates "Unsupported
Request Detected". Its not entirely clear to me what exact unsupported
request must have been sent. I've considered getting help to look at this
with a PCI analyzer but first I wanted to check and see if others are seeing
this with the 1008HA or similar platform familes and if there are pointers
some can give.

I'll consider sucking in patches to 2.6.32.2 if there is something on Linus'
tree on 2.6.33-rc1 but so far I can't even boot 2.6.33-rc1 on this thing so
it will have to be very selective.

The only other thing that might be relevant, not sure is the APCI error
messages I see during the first successfull resume:

[ 139.873054] ath9k: Starting driver with initial channel: 2462 MHz
[ 139.887477] ath9k: Attach a VIF of type: 2
[ 139.887511] ath9k: Set channel: 2462 MHz
[ 139.887516] ath9k: tx chmask: 1, rx chmask: 1
[ 139.887624] ath9k: (2462 MHz) -> (2462 MHz), chanwidth: 0
[ 139.896694] ath9k: Set HW RX filter: 0x607
[ 139.896701] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 139.896707] ath9k: BSS Changed PREAMBLE 1
[ 139.896711] ath9k: BSS Changed CTS PROT 0
[ 139.896715] ath9k: BSS Changed ASSOC 1
[ 139.896718] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 139.899489] PM: Finishing wakeup.
[ 139.899494] Restarting tasks ... done.
[ 139.934227] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 139.934270] activated addBA response timer on tid 0
[ 139.936192] Rx A-MPDU request on tid 0 result 0
[ 139.954281] switched off addBA timer for tid 0
[ 139.954289] Aggregation is on for tid 0
[ 140.571086] ACPI: EC: missing confirmations, switch off interrupt mode.
[ 141.076065] ACPI Exception: AE_TIME, Returned by Handler for [EmbeddedControl] 20090521 evregion-424
[ 141.076106] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.SBRG.EC0_.BST3] (Node f7013ea0), AE_TIME
[ 141.076205] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.CBST] (Node f70160a8), AE_TIME
[ 141.076249] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.BAT0._BST] (Node f7014fd8), AE_TIME
[ 141.076303] ACPI Exception: AE_TIME, Evaluating _BST 20090521 battery-385

I'll note though that I've even seen the ACPI error messages even
after a first busted resume. In that case the device already is
unresponsive before these ACPI messages.

Luis

2009-12-22 17:59:41

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 08:55:28AM -0800, Luis Rodriguez wrote:
> On Tue, Dec 22, 2009 at 08:20:55AM -0800, Luis Rodriguez wrote:
> > On Tue, Dec 22, 2009 at 07:50:05AM -0800, Luis Rodriguez wrote:
> > > On Mon, Dec 21, 2009 at 08:39:17PM -0800, Sujith Manoharan wrote:
> > > > Luis Rodriguez wrote:
> > > > > That log can be found here:
> > > > >
> > > > > http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt
> > > >
> > > > Thanks for the log.
> > > > It's a bug in ath9k, related to PowerSave.
> > > >
> > > > Can you test this patch ?
> > > >
> > > > diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> > > > index 3f5b887..419c382 100644
> > > > --- a/drivers/net/wireless/ath/ath9k/main.c
> > > > +++ b/drivers/net/wireless/ath/ath9k/main.c
> > > > @@ -2504,6 +2504,9 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > > > return; /* another wiphy still in use */
> > > > }
> > > >
> > > > + /* Ensure HW is awake when we try to shut it down. */
> > > > + ath9k_ps_wakeup(sc);
> > > > +
> > > > if (ah->btcoex_hw.enabled) {
> > > > ath9k_hw_btcoex_disable(ah);
> > > > if (ah->btcoex_hw.scheme == ATH_BTCOEX_CFG_3WIRE)
> > > > @@ -2524,8 +2527,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > > > /* disable HAL and put h/w to sleep */
> > > > ath9k_hw_disable(ah);
> > > > ath9k_hw_configpcipowersave(ah, 1, 1);
> > > > - ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > > > + ath9k_ps_restore(sc);
> > > >
> > > > + /* Finally, put the chip in FULL SLEEP mode */
> > > > + ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > > > sc->sc_flags |= SC_OP_INVALID;
> > > >
> > > > mutex_unlock(&sc->mutex);
> > >
> > >
> > > Thanks for the patch, doesn't cure it though. Below is the log
> > > with debug=0xa00 (CONFIG | PS), you can see some successes prior to
> > > the failure.
> >
> > Here's the new log with 0x601, with a few pm-suspend successes above.
>
> Let me massage this a little:
>
> Here is one success:
>
> > [ 249.543348] ath9k: NETWORK SLEEP -> AWAKE
> > [ 249.549393] ath9k: AWAKE -> NETWORK SLEEP
> > [ 249.577650] PM: Syncing filesystems ...
> > [ 249.645775] ath9k: NETWORK SLEEP -> AWAKE
> > [ 249.651822] ath9k: AWAKE -> NETWORK SLEEP
> > [ 249.677281] done.
> > [ 249.677291] PM: Preparing system for mem sleep
> > [ 249.748159] ath9k: NETWORK SLEEP -> AWAKE
> > [ 249.754256] ath9k: AWAKE -> NETWORK SLEEP
> > [ 249.765132] ath9k: NETWORK SLEEP -> AWAKE
>
> Device is awake prior to sending Tx BA.
>
> > [ 249.824923] Freezing user space processes ... (elapsed 0.00 seconds) done.
> > [ 249.826762] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> > [ 249.826830] PM: Entering mem sleep
> > [ 249.826853] Suspending console(s) (use no_console_suspend to debug)
> > [ 249.832057] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 249.832077] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
> > [ 249.832110] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 249.832130] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 6
> > [ 249.832141] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 6
> > [ 249.832166] ath9k: Detach Interface
> > [ 249.834435] ath9k: AWAKE -> FULL-SLEEP
> > [ 249.834446] ath9k: Driver halt
> > [ 249.858079] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> > [ 249.858457] sd 0:0:0:0: [sda] Stopping disk
> > [ 250.781437] ath9k 0000:01:00.0: PCI INT A disabled
>
> > [ 251.087088] Back to C!
>
> > [ 252.038696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> > [ 254.521068] ath9k: Starting driver with initial channel: 2437 MHz
> > [ 254.522086] ath9k: FULL-SLEEP -> AWAKE
> > [ 254.533094] ath9k: ah->misc_mode 0x4
> > [ 254.535214] ath9k: Attach a VIF of type: 2
> > [ 254.535248] ath9k: Set channel: 2437 MHz
> > [ 254.535252] ath9k: tx chmask: 1, rx chmask: 1
> > [ 254.535373] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
> > [ 254.541929] ath9k: ah->misc_mode 0x4
> > [ 254.544052] ath9k: Set HW RX filter: 0x607
> > [ 254.544058] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
> > [ 254.544065] ath9k: BSS Changed PREAMBLE 1
> > [ 254.544068] ath9k: BSS Changed CTS PROT 0
> > [ 254.544072] ath9k: BSS Changed ASSOC 1
> > [ 254.544076] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
> > [ 254.546454] PM: Finishing wakeup.
> > [ 254.546458] Restarting tasks ... done.
> > [ 254.589051] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
> > [ 254.589095] activated addBA response timer on tid 0
> > [ 254.615144] Rx A-MPDU request on tid 0 result 0
> > [ 254.717357] switched off addBA timer for tid 0
> > [ 254.717366] Aggregation is on for tid 0
> > [ 254.718297] switched off addBA timer for tid 0
>
> Then this is the failure suspend:
>
> > [ 270.574054] ath9k: NETWORK SLEEP -> AWAKE
> > [ 270.582421] ath9k: AWAKE -> NETWORK SLEEP
> > [ 270.676431] ath9k: NETWORK SLEEP -> AWAKE
> > [ 270.682643] ath9k: AWAKE -> NETWORK SLEEP
> > [ 270.778860] ath9k: NETWORK SLEEP -> AWAKE
> > [ 270.989686] ath9k: AWAKE -> NETWORK SLEEP
> > [ 271.049041] ath9k: NETWORK SLEEP -> AWAKE
> > [ 271.304833] PM: Syncing filesystems ... done.
> > [ 271.307636] PM: Preparing system for mem sleep
> > [ 271.399307] ath9k: AWAKE -> NETWORK SLEEP
>
> Below the device seems to go to sleep prior to sending the Tx BA, but I could have
> sworn this happens in another successfull suspend before.
>
> > [ 271.448580] Freezing user space processes ... (elapsed 0.00 seconds) done.
> > [ 271.450215] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> > [ 271.450296] PM: Entering mem sleep
> > [ 271.450321] Suspending console(s) (use no_console_suspend to debug)
> > [ 271.456054] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456073] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456112] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456141] ath9k: Detach Interface
> > [ 271.456161] ath9k: NETWORK SLEEP -> AWAKE
> > [ 271.458525] ath9k: AWAKE -> NETWORK SLEEP
> > [ 271.458533] ath9k: NETWORK SLEEP -> FULL-SLEEP
> > [ 271.458544] ath9k:
> > [ 271.458547] ath9k: Driver halt
> > [ 271.458552] FULL-SLEEP -> AWAKE
>
> And we leave it awake prior to suspend, hrm.
>
> > [ 271.485081] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> > [ 271.485444] sd 0:0:0:0: [sda] Stopping disk
> > [ 272.348209] ath9k 0000:01:00.0: PCI INT A disabled
>
> > [ 272.552139] Back to C!
>
> > [ 273.522696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> > [ 275.742070] ath9k: Starting driver with initial channel: 2437 MHz
> > [ 275.891791] ath9k: timeout (100000 us) on reg 0x7000: 0xdeadbeef & 0x00000003 != 0x00000000
> > [ 275.891799] ath9k: RTC stuck in MAC reset
>
> AT this point hardware is already completely unresonsive.
>
> > [ 275.891803] ath9k: Chip reset failed
> > [ 275.891807] ath9k: Unable to reset hardware; reset status -22 (freq 2437 MHz)
> > [ 275.891827] ath9k: Attach a VIF of type: 2
> > [ 275.891867] ath9k: Set channel: 2437 MHz
> > [ 275.891873] ath9k: tx chmask: 1, rx chmask: 1
> > [ 275.891880] ath9k: Unable to set channel
> > [ 275.891894] ath9k: Set HW RX filter: 0x2707
> > [ 275.891901] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
> > [ 275.891910] ath9k: BSS Changed PREAMBLE 1
> > [ 275.891915] ath9k: BSS Changed CTS PROT 0
> > [ 275.891919] ath9k: BSS Changed ASSOC 1
> > [ 275.891924] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
> > [ 275.894481] PM: Finishing wakeup.
> > [ 275.894486] Restarting tasks ... done.
> > [ 276.835592] irq 18: nobody cared (try booting with the "irqpoll" option)
> > [ 276.835609] Pid: 1710, comm: Xorg Not tainted 2.6.31.4-intel-menlow #14
> > [ 276.835616] Call Trace:
> > [ 276.835636] [<c105ca3e>] __report_bad_irq+0x2e/0x6f
> > [ 276.835646] [<c105cb74>] note_interrupt+0xf5/0x14d
> > [ 276.835656] [<c105d0a4>] handle_fasteoi_irq+0x7d/0x9b
> > [ 276.835668] [<c10048c1>] handle_irq+0x3b/0x46
> > [ 276.835677] [<c1004103>] do_IRQ+0x41/0x95
> > [ 276.835687] [<c1003189>] common_interrupt+0x29/0x30
> > [ 276.835693] handlers:
> > [ 276.835698] [<f89a3d03>] (ath_isr+0x0/0x12f [ath9k])
> > [ 276.835739] Disabling IRQ #18

Here's a new log with a two printks added as follows:

diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
index 420e165..a74f9db 100644
--- a/drivers/net/wireless/ath/ath9k/main.c
+++ b/drivers/net/wireless/ath/ath9k/main.c
@@ -2145,6 +2145,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
return; /* another wiphy still in use */
}

+ /* Ensure HW is awake when we try to shut it down. */
+ printk("== Wake up!\n");
+ ath9k_ps_wakeup(sc);
+
if (sc->sc_flags & SC_OP_BTCOEX_ENABLED) {
ath9k_hw_btcoex_disable(sc->sc_ah);
if (sc->btcoex_info.btcoex_scheme == ATH_BTCOEX_CFG_3WIRE)
@@ -2165,7 +2169,11 @@ static void ath9k_stop(struct ieee80211_hw *hw)
/* disable HAL and put h/w to sleep */
ath9k_hw_disable(sc->sc_ah);
ath9k_hw_configpcipowersave(sc->sc_ah, 1, 1);
+ ath9k_ps_restore(sc);
+
+ /* Finally, put the chip in FULL SLEEP mode */
ath9k_hw_setpower(sc->sc_ah, ATH9K_PM_FULL_SLEEP);
+ printk("== Sleep!\n");

sc->sc_flags |= SC_OP_INVALID;

And the log, massaged to keep only relevant sections below.

Suspend success cycle #1:

[ 182.156952] ath9k: AWAKE -> NETWORK SLEEP
[ 182.253322] ath9k: NETWORK SLEEP -> AWAKE
[ 182.260175] ath9k: AWAKE -> NETWORK SLEEP
[ 182.355720] ath9k: NETWORK SLEEP -> AWAKE
[ 182.361755] ath9k: AWAKE -> NETWORK SLEEP
[ 182.458145] ath9k: NETWORK SLEEP -> AWAKE
[ 182.459914] PM: Syncing filesystems ...
[ 182.660736] ath9k: AWAKE -> NETWORK SLEEP
[ 182.662924] ath9k: NETWORK SLEEP -> AWAKE
[ 182.681816] ath9k: AWAKE -> NETWORK SLEEP
[ 182.765356] ath9k: NETWORK SLEEP -> AWAKE
[ 182.784954] ath9k: AWAKE -> NETWORK SLEEP
[ 182.798240] done.
[ 182.798250] PM: Preparing system for mem sleep
[ 182.867751] ath9k: NETWORK SLEEP -> AWAKE
[ 182.876104] ath9k: AWAKE -> NETWORK SLEEP

Note device in NETWORK_SLEEP and below we send Tx BA.

[ 182.944721] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 182.946141] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 182.946222] PM: Entering mem sleep
[ 182.946245] Suspending console(s) (use no_console_suspend to debug)
[ 182.950334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 182.950354] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 182.950392] ath9k:
[ 182.950403] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0

We awaken only for the Tx BA for TID 6 below.

[ 182.950410] NETWORK SLEEP -> AWAKE
[ 182.950429] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 6
[ 182.950444] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 6
[ 182.950509] ath9k: Detach Interface
[ 182.950527] == Wake up!
[ 182.952768] ath9k: AWAKE -> FULL-SLEEP
[ 182.952779] == Sleep!

[ 182.952781] ath9k: Driver halt
[ 182.976080] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 182.976457] sd 0:0:0:0: [sda] Stopping disk
[ 183.908332] ath9k 0000:01:00.0: PCI INT A disabled
[ 183.932618] ACPI handle has no context!
[ 183.932632] atl1c 0000:02:00.0: PME# disabled
[ 183.932643] atl1c 0000:02:00.0: PCI INT A disabled
[ 183.932653] ACPI handle has no context!
[ 183.976158] ata6: port disabled. ignoring.
[ 183.976246] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 183.976264] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 183.976276] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 183.976287] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 183.976298] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 183.976309] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 183.994731] i915 0000:00:02.0: PCI INT A disabled
[ 184.005417] ehci_hcd 0000:00:1d.7: PME# disabled
[ 184.016463] ACPI: Preparing to enter system sleep state S3
[ 184.104766] Disabling non-boot CPUs ...
[ 184.107102] CPU 1 is now offline
[ 184.107108] SMP alternatives: switching to UP code
[ 184.111140] CPU1 is down
[ 184.111163] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106

[ 184.111163] Back to C!


[ 185.060698] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 187.457073] ath9k: Starting driver with initial channel: 2437 MHz
[ 187.458091] ath9k: FULL-SLEEP -> AWAKE
[ 187.469043] ath9k: ah->misc_mode 0x4
[ 187.471159] ath9k: Attach a VIF of type: 2
[ 187.471191] ath9k: Set channel: 2437 MHz
[ 187.471196] ath9k: tx chmask: 1, rx chmask: 1
[ 187.471317] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 187.477858] ath9k: ah->misc_mode 0x4
[ 187.479976] ath9k: Set HW RX filter: 0x607
[ 187.479982] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 187.479989] ath9k: BSS Changed PREAMBLE 1
[ 187.479992] ath9k: BSS Changed CTS PROT 0
[ 187.479996] ath9k: BSS Changed ASSOC 1
[ 187.480000] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 187.482457] PM: Finishing wakeup.
[ 187.482462] Restarting tasks ... done.
[ 187.530036] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 187.530077] activated addBA response timer on tid 0
[ 187.537252] Rx A-MPDU request on tid 0 result 0
[ 187.541097] switched off addBA timer for tid 0
[ 187.541104] Aggregation is on for tid 0
[ 187.749356] ath9k: AWAKE -> NETWORK SLEEP
[ 187.775809] ath9k: NETWORK SLEEP -> AWAKE

etc

second pm-suspend success:

[ 192.212022] ath9k: NETWORK SLEEP -> AWAKE
[ 192.218060] ath9k: AWAKE -> NETWORK SLEEP
[ 192.231965] PM: Syncing filesystems ...
[ 192.314416] ath9k: NETWORK SLEEP -> AWAKE
[ 192.327533] ath9k: AWAKE -> NETWORK SLEEP
[ 192.416841] ath9k: NETWORK SLEEP -> AWAKE
[ 192.427949] ath9k: AWAKE -> NETWORK SLEEP
[ 192.455560] done.
[ 192.455569] PM: Preparing system for mem sleep
[ 192.519226] ath9k: NETWORK SLEEP -> AWAKE
[ 192.525257] ath9k: AWAKE -> NETWORK SLEEP
[ 192.530138] ath9k: NETWORK SLEEP -> AWAKE

Device AWAKE prior to sending the Tx BA on both TIDs below.

[ 192.602902] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 192.604579] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 192.604654] PM: Entering mem sleep
[ 192.604675] Suspending console(s) (use no_console_suspend to debug)
[ 192.610334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 192.610355] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 192.610387] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 192.610414] ath9k: Detach Interface
[ 192.610427] == Wake up!
[ 192.612705] ath9k: AWAKE -> FULL-SLEEP
[ 192.612716] == Sleep!

Device now asleep..

[ 192.612719] ath9k: Driver halt
[ 192.635080] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 192.635448] sd 0:0:0:0: [sda] Stopping disk
[ 193.485094] ath9k 0000:01:00.0: PCI INT A disabled
[ 193.509614] ACPI handle has no context!

Suspeneded.

[ 193.685151] Back to C!

[ 193.765036] ACPI: Waking up from system sleep state S3
[ 194.623693] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 196.841100] ath9k: FULL-SLEEP -> AWAKE
[ 196.852089] ath9k: ah->misc_mode 0x4
[ 196.854196] ath9k: Attach a VIF of type: 2
[ 196.854229] ath9k: Set channel: 2437 MHz
[ 196.854233] ath9k: tx chmask: 1, rx chmask: 1
[ 196.854355] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 196.860891] ath9k: ah->misc_mode 0x4
[ 196.863000] ath9k: Set HW RX filter: 0x607
[ 196.863021] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 196.863027] ath9k: BSS Changed PREAMBLE 1
[ 196.863031] ath9k: BSS Changed CTS PROT 0
[ 196.863035] ath9k: BSS Changed ASSOC 1
[ 196.863038] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 196.865482] PM: Finishing wakeup.
[ 196.865487] Restarting tasks ... done.
[ 196.889882] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 196.889916] activated addBA response timer on tid 0
[ 196.895041] Rx A-MPDU request on tid 0 result 0
[ 196.897663] switched off addBA timer for tid 0
[ 196.897671] Aggregation is on for tid 0
[ 197.006590] ath9k: AWAKE -> NETWORK SLEEP
[ 197.892811] ath9k: NETWORK SLEEP -> AWAKE

Shake and bake.

And then immediatey another quick suspend (#4) right after:

[ 198.098735] ath9k: AWAKE -> NETWORK SLEEP
[ 198.894095] ath9k: NETWORK SLEEP -> AWAKE
[ 199.021250] ath9k: AWAKE -> NETWORK SLEEP
[ 199.895581] ath9k: NETWORK SLEEP -> AWAKE
[ 200.028475] ath9k: AWAKE -> NETWORK SLEEP
[ 200.902321] ath9k: NETWORK SLEEP -> AWAKE
[ 201.027363] ath9k: AWAKE -> NETWORK SLEEP
[ 201.605981] ath9k: NETWORK SLEEP -> AWAKE
[ 201.731412] ath9k: AWAKE -> NETWORK SLEEP
[ 201.903590] ath9k: NETWORK SLEEP -> AWAKE
[ 201.948356] PM: Syncing filesystems ...
[ 202.030148] ath9k: AWAKE -> NETWORK SLEEP
[ 202.161849] done.
[ 202.161859] PM: Preparing system for mem sleep
[ 202.305059] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 202.306442] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 202.306525] PM: Entering mem sleep
[ 202.306547] Suspending console(s) (use no_console_suspend to debug)

Device in NETWORK_SLEEP state prior to sendign the Tx BA for TID 0,
nothing was sent for Tid 6 as no BA session was established after
resume, it was a quick resume --> suspend cycle.

[ 202.311334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 202.311354] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 202.311393] ath9k:
[ 202.311402] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 202.311411] NETWORK SLEEP -> AWAKE
[ 202.311506] ath9k: Detach Interface
[ 202.311525] == Wake up!
[ 202.313823] ath9k: AWAKE -> FULL-SLEEP
[ 202.313834] == Sleep!
[ 202.313836] ath9k: Driver halt
[ 203.281163] ath9k 0000:01:00.0: PCI INT A disabled
[ 203.305614] ACPI handle has no context!


[ 203.483156] Back to C!

Waking up from suspend #4 now.


[ 203.561036] ACPI: Waking up from system sleep state S3
[ 204.430697] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 206.660077] ath9k: Starting driver with initial channel: 2437 MHz
[ 206.661096] ath9k: FULL-SLEEP -> AWAKE
[ 206.672056] ath9k: ah->misc_mode 0x4
[ 206.674176] ath9k: Attach a VIF of type: 2
[ 206.674209] ath9k: Set channel: 2437 MHz
[ 206.674214] ath9k: tx chmask: 1, rx chmask: 1
[ 206.674335] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 206.680870] ath9k: ah->misc_mode 0x4
[ 206.682973] ath9k: Set HW RX filter: 0x607
[ 206.682980] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 206.682986] ath9k: BSS Changed PREAMBLE 1
[ 206.682990] ath9k: BSS Changed CTS PROT 0
[ 206.682994] ath9k: BSS Changed ASSOC 1
[ 206.682997] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 206.685445] PM: Finishing wakeup.
[ 206.685449] Restarting tasks ... done.
[ 206.721949] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 206.721994] activated addBA response timer on tid 0
[ 206.726181] Rx A-MPDU request on tid 0 result 0
[ 206.728552] switched off addBA timer for tid 0
[ 206.728560] Aggregation is on for tid 0
[ 206.832028] ath9k: AWAKE -> NETWORK SLEEP
[ 207.716419] ath9k: NETWORK SLEEP -> AWAKE
[ 207.848507] ath9k: AWAKE -> NETWORK SLEEP

etc..

Here's another sucessfull suspend (#5):

[ 210.821393] ath9k: NETWORK SLEEP -> AWAKE
[ 210.821468] ath9k: AWAKE -> NETWORK SLEEP
[ 210.831262] ath9k: NETWORK SLEEP -> AWAKE
[ 210.936498] ath9k: AWAKE -> NETWORK SLEEP
[ 211.463078] PM: Syncing filesystems ... done.
[ 211.670449] PM: Preparing system for mem sleep
[ 211.723388] ath9k: NETWORK SLEEP -> AWAKE

Device awake prior to sending Tx BA stop request on TID 0:

[ 211.818907] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 211.820532] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 211.820611] PM: Entering mem sleep
[ 211.820633] Suspending console(s) (use no_console_suspend to debug)
[ 211.826059] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 211.826078] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 211.826113] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 211.826141] ath9k: Detach Interface
[ 211.826155] == Wake up!
[ 211.828465] ath9k: AWAKE -> FULL-SLEEP
[ 211.828476] == Sleep!
[ 211.828478] ath9k: Driver halt
[ 212.702026] ath9k 0000:01:00.0: PCI INT A disabled
[ 212.726613] ACPI handle has no context!
[ 212.807467] ACPI: Preparing to enter system sleep state S3

[ 212.906162] Back to C!

[ 213.863686] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 216.080072] ath9k: Starting driver with initial channel: 2437 MHz
[ 216.081090] ath9k: FULL-SLEEP -> AWAKE
[ 216.092044] ath9k: ah->misc_mode 0x4
[ 216.094160] ath9k: Attach a VIF of type: 2
[ 216.094193] ath9k: Set channel: 2437 MHz
[ 216.094197] ath9k: tx chmask: 1, rx chmask: 1
[ 216.094320] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 216.100867] ath9k: ah->misc_mode 0x4
[ 216.102987] ath9k: Set HW RX filter: 0x607
[ 216.102994] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 216.103014] ath9k: BSS Changed PREAMBLE 1
[ 216.103018] ath9k: BSS Changed CTS PROT 0
[ 216.103022] ath9k: BSS Changed ASSOC 1
[ 216.103025] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 216.105477] PM: Finishing wakeup.
[ 216.105481] Restarting tasks ... done.
[ 216.128225] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 216.128259] activated addBA response timer on tid 0
[ 216.130182] Rx A-MPDU request on tid 0 result 0
[ 216.139669] switched off addBA timer for tid 0
[ 216.139677] Aggregation is on for tid 0

Ok resume from suspend #5 complete. Now here goes another successfull
suspend but with some complaints from ACPI noted.

[ 216.237502] ath9k: AWAKE -> NETWORK SLEEP
[ 217.129138] ath9k: NETWORK SLEEP -> AWAKE
[ 217.240499] ath9k: AWAKE -> NETWORK SLEEP
[ 218.130666] ath9k: NETWORK SLEEP -> AWAKE
[ 218.245793] ath9k: AWAKE -> NETWORK SLEEP
[ 219.132386] ath9k: NETWORK SLEEP -> AWAKE
[ 219.288081] ath9k: AWAKE -> NETWORK SLEEP
[ 220.034303] ACPI: EC: missing confirmations, switch off interrupt mode.

Wonder what that is..

[ 220.133204] ath9k: NETWORK SLEEP -> AWAKE
[ 220.287540] ath9k: AWAKE -> NETWORK SLEEP
[ 220.287596] ath9k: NETWORK SLEEP -> AWAKE
[ 220.287678] ath9k: AWAKE -> NETWORK SLEEP
[ 220.304659] ath9k: NETWORK SLEEP -> AWAKE
[ 220.304780] ath9k: AWAKE -> NETWORK SLEEP
[ 220.305334] ath9k: NETWORK SLEEP -> AWAKE
[ 220.407614] ath9k: AWAKE -> NETWORK SLEEP
[ 220.538072] ACPI Exception: AE_TIME, Returned by Handler for [EmbeddedControl] 20090521 evregion-424
[ 220.538112] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.SBRG.EC0_.BST2] (Node f7013e88), AE_TIME
[ 220.538208] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.CBST] (Node f70160a8), AE_TIME
[ 220.538251] ACPI Error (psparse-0537): Method parse/execution failed [\_SB_.PCI0.BAT0._BST] (Node f7014fd8), AE_TIME
[ 220.538341] ACPI Exception: AE_TIME, Evaluating _BST 20090521 battery-385

There goes that ACPI excemption.

Here goes successfull suspend #6:

[ 220.565306] PM: Syncing filesystems ... done.
[ 220.812903] PM: Preparing system for mem sleep
[ 220.959826] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 220.961228] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 220.961314] PM: Entering mem sleep
[ 220.961336] Suspending console(s) (use no_console_suspend to debug)
[ 220.966334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0

Note, we send the Tx BA session stop reequest when device is in NETWORK_SLEEP.

[ 220.966353] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 220.966392] ath9k:
[ 220.966401] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 220.966410] NETWORK SLEEP -> AWAKE
[ 220.966506] ath9k: Detach Interface
[ 220.966524] == Wake up!
[ 220.968800] ath9k: AWAKE -> FULL-SLEEP
[ 220.968810] == Sleep!
[ 220.968813] ath9k: Driver halt
[ 221.920357] ath9k 0000:01:00.0: PCI INT A disabled
[ 221.944617] ACPI handle has no context!

[ 222.026467] ACPI: Preparing to enter system sleep state S3

[ 222.134152] Back to C!

[ 223.082691] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18

[ 225.298081] ath9k: Starting driver with initial channel: 2437 MHz
[ 225.299099] ath9k: FULL-SLEEP -> AWAKE
[ 225.310044] ath9k: ah->misc_mode 0x4
[ 225.312175] ath9k: Attach a VIF of type: 2
[ 225.312208] ath9k: Set channel: 2437 MHz
[ 225.312212] ath9k: tx chmask: 1, rx chmask: 1
[ 225.312334] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 225.318873] ath9k: ah->misc_mode 0x4
[ 225.320975] ath9k: Set HW RX filter: 0x607
[ 225.320981] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 225.320987] ath9k: BSS Changed PREAMBLE 1
[ 225.320991] ath9k: BSS Changed CTS PROT 0
[ 225.320995] ath9k: BSS Changed ASSOC 1
[ 225.320998] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 225.323482] PM: Finishing wakeup.
[ 225.323486] Restarting tasks ... done.
[ 225.350006] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 225.350075] activated addBA response timer on tid 0
[ 225.351993] Rx A-MPDU request on tid 0 result 0
[ 225.354056] switched off addBA timer for tid 0
[ 225.354064] Aggregation is on for tid 0
[ 225.453681] ath9k: AWAKE -> NETWORK SLEEP
[ 226.348955] ath9k: NETWORK SLEEP -> AWAKE
[ 226.529134] ath9k: AWAKE -> NETWORK SLEEP
[ 227.350638] ath9k: NETWORK SLEEP -> AWAKE
[ 227.537846] ath9k: AWAKE -> NETWORK SLEEP
[ 228.352545] ath9k: NETWORK SLEEP -> AWAKE
[ 228.497730] ath9k: AWAKE -> NETWORK SLEEP
[ 229.353944] ath9k: NETWORK SLEEP -> AWAKE
[ 229.546220] ath9k: AWAKE -> NETWORK SLEEP
[ 230.356288] ath9k: NETWORK SLEEP -> AWAKE
[ 230.503293] ath9k: AWAKE -> NETWORK SLEEP

And we're up again.




Here's the failure coming up now. On the 6th suspend this time:

[ 230.560286] PM: Syncing filesystems ...
[ 230.599622] ath9k: NETWORK SLEEP -> AWAKE
[ 230.708382] ath9k: AWAKE -> NETWORK SLEEP
[ 230.806539] done.
[ 230.806549] PM: Preparing system for mem sleep
[ 230.952445] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 230.953807] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 230.953892] PM: Entering mem sleep
[ 230.953915] Suspending console(s) (use no_console_suspend to debug)
[ 230.958315] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 230.958335] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 230.958374] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 230.958402] ath9k: Detach Interface

In NETWORK_SLEEP while we Tx BA session stop request for TID 0 above.
But that's not the only thing we do here, we also call
ath9k_remove_interface() while in NETWORK_SLEEP which could cause
an issue. Its the only thing strikingly odd which I notice from
the logs.

After this we proceed to rest of the suspend, below starts
the ath9k_stop()

[ 230.958421] == Wake up!
[ 230.958426] ath9k: NETWORK SLEEP -> AWAKE
[ 230.960795] ath9k: AWAKE -> NETWORK SLEEP
[ 230.960802] ath9k: NETWORK SLEEP -> FULL-SLEEP
[ 230.960812] == Sleep!
[ 230.960814] ath9k: Driver halt

ath9k_stop() ends here.

[ 230.960823] ath9k: FULL-SLEEP -> AWAKE
[ 231.859368] ath9k 0000:01:00.0: PCI INT A disabled
[ 231.883613] ACPI handle has no context!

[ 232.062155] Back to C!

[ 232.140041] ACPI: Waking up from system sleep state S3
[ 233.028686] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 235.248074] ath9k: Starting driver with initial channel: 2437 MHz
[ 235.397220] ath9k: timeout (100000 us) on reg 0x7000: 0xdeadbeef & 0x00000003 != 0x00000000
[ 235.397228] ath9k: RTC stuck in MAC reset

Bleh.

[ 235.397232] ath9k: Chip reset failed
[ 235.397236] ath9k: Unable to reset hardware; reset status -22 (freq 2437 MHz)
[ 235.397266] ath9k: Attach a VIF of type: 2
[ 235.397314] ath9k: Set channel: 2437 MHz
[ 235.397320] ath9k: tx chmask: 1, rx chmask: 1
[ 235.397326] ath9k: Unable to set channel
[ 235.397340] ath9k: Set HW RX filter: 0x2707
[ 235.397348] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 235.397356] ath9k: BSS Changed PREAMBLE 1
[ 235.397361] ath9k: BSS Changed CTS PROT 0
[ 235.397366] ath9k: BSS Changed ASSOC 1
[ 235.397371] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 235.400473] PM: Finishing wakeup.
[ 235.400479] Restarting tasks ... done.
[ 236.263277] irq 18: nobody cared (try booting with the "irqpoll" option)
[ 236.263293] Pid: 1773, comm: Xorg Not tainted 2.6.31.4-intel-menlow #15
[ 236.263300] Call Trace:
[ 236.263318] [<c105ca3e>] __report_bad_irq+0x2e/0x6f
[ 236.263329] [<c105cb74>] note_interrupt+0xf5/0x14d
[ 236.263341] [<c105d0a4>] handle_fasteoi_irq+0x7d/0x9b
[ 236.263352] [<c10048c1>] handle_irq+0x3b/0x46
[ 236.263362] [<c1004103>] do_IRQ+0x41/0x95
[ 236.263372] [<c1003189>] common_interrupt+0x29/0x30
[ 236.263379] handlers:
[ 236.263384] [<f8a2cd1b>] (ath_isr+0x0/0x12f [ath9k])
[ 236.263423] Disabling IRQ #18

I just tried adding the PM stuff over ath9k_remove_interface and I still get the
issue. The patch is below.

diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
index 420e165..4cb38b6 100644
--- a/drivers/net/wireless/ath/ath9k/main.c
+++ b/drivers/net/wireless/ath/ath9k/main.c
@@ -2145,6 +2145,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
return; /* another wiphy still in use */
}

+ /* Ensure HW is awake when we try to shut it down. */
+ printk("== Wake up!\n");
+ ath9k_ps_wakeup(sc);
+
if (sc->sc_flags & SC_OP_BTCOEX_ENABLED) {
ath9k_hw_btcoex_disable(sc->sc_ah);
if (sc->btcoex_info.btcoex_scheme == ATH_BTCOEX_CFG_3WIRE)
@@ -2165,7 +2169,11 @@ static void ath9k_stop(struct ieee80211_hw *hw)
/* disable HAL and put h/w to sleep */
ath9k_hw_disable(sc->sc_ah);
ath9k_hw_configpcipowersave(sc->sc_ah, 1, 1);
+ ath9k_ps_restore(sc);
+
+ /* Finally, put the chip in FULL SLEEP mode */
ath9k_hw_setpower(sc->sc_ah, ATH9K_PM_FULL_SLEEP);
+ printk("== Sleep!\n");

sc->sc_flags |= SC_OP_INVALID;

@@ -2268,6 +2276,8 @@ static void ath9k_remove_interface(struct ieee80211_hw *hw,

mutex_lock(&sc->mutex);

+ ath9k_ps_wakeup(sc);
+
/* Stop ANI */
del_timer_sync(&sc->ani.timer);

@@ -2292,6 +2302,8 @@ static void ath9k_remove_interface(struct ieee80211_hw *hw,

sc->nvifs--;

+ ath9k_ps_restore(sc);
+
mutex_unlock(&sc->mutex);
}

Luis

2009-12-23 03:49:56

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis Rodriguez wrote:
> > diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> > index 419c382..7fdcc6b 100644
> > --- a/drivers/net/wireless/ath/ath9k/main.c
> > +++ b/drivers/net/wireless/ath/ath9k/main.c
> > @@ -2673,6 +2673,11 @@ static int ath9k_config(struct ieee80211_hw *hw, u32 changed)
> >
> > mutex_lock(&sc->mutex);
> >
> > + if (sc->sc_flags & SC_OP_INVALID) {
> > + mutex_unlock(&sc->mutex);
> > + return 0;
> > + }
> > +
> > /*
> > * Leave this as the first check because we need to turn on the
> > * radio if it was disabled before prior to processing the rest
>
> That ones busts the resume.

Weird, checking for the device status before allowing configuration
changes is valid. Not sure why this is happening.

Sujith

2009-12-22 16:20:56

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 07:50:05AM -0800, Luis Rodriguez wrote:
> On Mon, Dec 21, 2009 at 08:39:17PM -0800, Sujith Manoharan wrote:
> > Luis Rodriguez wrote:
> > > That log can be found here:
> > >
> > > http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt
> >
> > Thanks for the log.
> > It's a bug in ath9k, related to PowerSave.
> >
> > Can you test this patch ?
> >
> > diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> > index 3f5b887..419c382 100644
> > --- a/drivers/net/wireless/ath/ath9k/main.c
> > +++ b/drivers/net/wireless/ath/ath9k/main.c
> > @@ -2504,6 +2504,9 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > return; /* another wiphy still in use */
> > }
> >
> > + /* Ensure HW is awake when we try to shut it down. */
> > + ath9k_ps_wakeup(sc);
> > +
> > if (ah->btcoex_hw.enabled) {
> > ath9k_hw_btcoex_disable(ah);
> > if (ah->btcoex_hw.scheme == ATH_BTCOEX_CFG_3WIRE)
> > @@ -2524,8 +2527,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > /* disable HAL and put h/w to sleep */
> > ath9k_hw_disable(ah);
> > ath9k_hw_configpcipowersave(ah, 1, 1);
> > - ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > + ath9k_ps_restore(sc);
> >
> > + /* Finally, put the chip in FULL SLEEP mode */
> > + ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > sc->sc_flags |= SC_OP_INVALID;
> >
> > mutex_unlock(&sc->mutex);
>
>
> Thanks for the patch, doesn't cure it though. Below is the log
> with debug=0xa00 (CONFIG | PS), you can see some successes prior to
> the failure.

Here's the new log with 0x601, with a few pm-suspend successes above.

[ 230.291057] ath9k: NETWORK SLEEP -> AWAKE
[ 230.501901] ath9k: AWAKE -> NETWORK SLEEP
[ 230.598294] ath9k: NETWORK SLEEP -> AWAKE
[ 230.610304] ath9k: AWAKE -> NETWORK SLEEP
[ 230.700688] ath9k: NETWORK SLEEP -> AWAKE
[ 230.707386] ath9k: AWAKE -> NETWORK SLEEP
[ 230.803081] ath9k: NETWORK SLEEP -> AWAKE
[ 231.016430] ath9k: AWAKE -> NETWORK SLEEP
[ 231.110303] ath9k: NETWORK SLEEP -> AWAKE
[ 231.116346] ath9k: AWAKE -> NETWORK SLEEP
[ 231.212720] ath9k: NETWORK SLEEP -> AWAKE
[ 231.218898] ath9k: AWAKE -> NETWORK SLEEP
[ 231.315118] ath9k: NETWORK SLEEP -> AWAKE
[ 231.321157] ath9k: AWAKE -> NETWORK SLEEP
[ 231.417543] ath9k: NETWORK SLEEP -> AWAKE
[ 231.427228] ath9k: AWAKE -> NETWORK SLEEP
[ 231.519935] ath9k: NETWORK SLEEP -> AWAKE
[ 231.526496] ath9k: AWAKE -> NETWORK SLEEP
[ 231.622328] ath9k: NETWORK SLEEP -> AWAKE
[ 231.629912] ath9k: AWAKE -> NETWORK SLEEP
[ 231.724753] ath9k: NETWORK SLEEP -> AWAKE
[ 231.730773] ath9k: AWAKE -> NETWORK SLEEP
[ 231.827147] ath9k: NETWORK SLEEP -> AWAKE
[ 231.833176] ath9k: AWAKE -> NETWORK SLEEP
[ 231.929541] ath9k: NETWORK SLEEP -> AWAKE
[ 231.940075] ath9k: AWAKE -> NETWORK SLEEP
[ 232.031968] ath9k: NETWORK SLEEP -> AWAKE
[ 232.041398] ath9k: AWAKE -> NETWORK SLEEP
[ 232.134364] ath9k: NETWORK SLEEP -> AWAKE
[ 232.144893] ath9k: AWAKE -> NETWORK SLEEP
[ 232.236790] ath9k: NETWORK SLEEP -> AWAKE
[ 232.242808] ath9k: AWAKE -> NETWORK SLEEP
[ 232.339183] ath9k: NETWORK SLEEP -> AWAKE
[ 232.346675] ath9k: AWAKE -> NETWORK SLEEP
[ 232.441577] ath9k: NETWORK SLEEP -> AWAKE
[ 232.447621] ath9k: AWAKE -> NETWORK SLEEP
[ 232.543998] ath9k: NETWORK SLEEP -> AWAKE
[ 232.551040] ath9k: AWAKE -> NETWORK SLEEP
[ 232.630348] ath9k: NETWORK SLEEP -> AWAKE
[ 232.821147] ath9k: AWAKE -> NETWORK SLEEP
[ 232.851209] ath9k: NETWORK SLEEP -> AWAKE
[ 232.858137] ath9k: AWAKE -> NETWORK SLEEP
[ 232.953605] ath9k: NETWORK SLEEP -> AWAKE
[ 232.959647] ath9k: AWAKE -> NETWORK SLEEP
[ 233.056033] ath9k: NETWORK SLEEP -> AWAKE
[ 233.267729] ath9k: AWAKE -> NETWORK SLEEP
[ 233.302127] ath9k: NETWORK SLEEP -> AWAKE
[ 233.425646] ath9k: AWAKE -> NETWORK SLEEP
[ 233.465642] ath9k: NETWORK SLEEP -> AWAKE
[ 233.574250] ath9k: AWAKE -> NETWORK SLEEP
[ 233.670460] ath9k: NETWORK SLEEP -> AWAKE
[ 233.683240] ath9k: AWAKE -> NETWORK SLEEP
[ 233.772853] ath9k: NETWORK SLEEP -> AWAKE
[ 233.779182] ath9k: AWAKE -> NETWORK SLEEP
[ 233.875280] ath9k: NETWORK SLEEP -> AWAKE
[ 233.881299] ath9k: AWAKE -> NETWORK SLEEP
[ 233.977672] ath9k: NETWORK SLEEP -> AWAKE
[ 233.986397] ath9k: AWAKE -> NETWORK SLEEP
[ 234.080059] ath9k: NETWORK SLEEP -> AWAKE
[ 234.086942] ath9k: AWAKE -> NETWORK SLEEP
[ 234.162736] ath9k: NETWORK SLEEP -> AWAKE
[ 234.162840] ath9k: AWAKE -> NETWORK SLEEP
[ 234.162851] ath9k: Set HW RX filter: 0x607
[ 234.182494] ath9k: NETWORK SLEEP -> AWAKE
[ 234.192203] ath9k: AWAKE -> NETWORK SLEEP
[ 234.284887] ath9k: NETWORK SLEEP -> AWAKE
[ 234.393325] ath9k: AWAKE -> NETWORK SLEEP
[ 234.489707] ath9k: NETWORK SLEEP -> AWAKE
[ 234.495950] ath9k: AWAKE -> NETWORK SLEEP
[ 234.592087] ath9k: NETWORK SLEEP -> AWAKE
[ 234.610548] ath9k: AWAKE -> NETWORK SLEEP
[ 234.694526] ath9k: NETWORK SLEEP -> AWAKE
[ 234.700856] ath9k: AWAKE -> NETWORK SLEEP
[ 234.796918] ath9k: NETWORK SLEEP -> AWAKE
[ 234.803175] ath9k: AWAKE -> NETWORK SLEEP
[ 234.899313] ath9k: NETWORK SLEEP -> AWAKE
[ 234.905352] ath9k: AWAKE -> NETWORK SLEEP
[ 235.001735] ath9k: NETWORK SLEEP -> AWAKE
[ 235.008164] ath9k: AWAKE -> NETWORK SLEEP
[ 235.104133] ath9k: NETWORK SLEEP -> AWAKE
[ 235.110377] ath9k: AWAKE -> NETWORK SLEEP
[ 235.206557] ath9k: NETWORK SLEEP -> AWAKE
[ 235.212696] ath9k: AWAKE -> NETWORK SLEEP
[ 235.308953] ath9k: NETWORK SLEEP -> AWAKE
[ 235.326431] ath9k: AWAKE -> NETWORK SLEEP
[ 235.411345] ath9k: NETWORK SLEEP -> AWAKE
[ 235.418223] ath9k: AWAKE -> NETWORK SLEEP
[ 235.513772] ath9k: NETWORK SLEEP -> AWAKE
[ 235.622198] ath9k: AWAKE -> NETWORK SLEEP
[ 235.718560] ath9k: NETWORK SLEEP -> AWAKE
[ 235.725249] ath9k: AWAKE -> NETWORK SLEEP
[ 235.820984] ath9k: NETWORK SLEEP -> AWAKE
[ 235.830516] ath9k: AWAKE -> NETWORK SLEEP
[ 235.923380] ath9k: NETWORK SLEEP -> AWAKE
[ 235.931702] ath9k: AWAKE -> NETWORK SLEEP
[ 236.025804] ath9k: NETWORK SLEEP -> AWAKE
[ 236.134230] ath9k: AWAKE -> NETWORK SLEEP
[ 236.230592] ath9k: NETWORK SLEEP -> AWAKE
[ 236.239172] ath9k: AWAKE -> NETWORK SLEEP
[ 236.333017] ath9k: NETWORK SLEEP -> AWAKE
[ 236.340680] ath9k: AWAKE -> NETWORK SLEEP
[ 236.435411] ath9k: NETWORK SLEEP -> AWAKE
[ 236.442458] ath9k: AWAKE -> NETWORK SLEEP
[ 236.537802] ath9k: NETWORK SLEEP -> AWAKE
[ 236.545238] ath9k: AWAKE -> NETWORK SLEEP
[ 236.640230] ath9k: NETWORK SLEEP -> AWAKE
[ 236.647491] ath9k: AWAKE -> NETWORK SLEEP
[ 236.742624] ath9k: NETWORK SLEEP -> AWAKE
[ 236.761241] ath9k: AWAKE -> NETWORK SLEEP
[ 236.845049] ath9k: NETWORK SLEEP -> AWAKE
[ 236.851557] ath9k: AWAKE -> NETWORK SLEEP
[ 236.947442] ath9k: NETWORK SLEEP -> AWAKE
[ 236.953910] ath9k: AWAKE -> NETWORK SLEEP
[ 237.049837] ath9k: NETWORK SLEEP -> AWAKE
[ 237.056854] ath9k: AWAKE -> NETWORK SLEEP
[ 237.152265] ath9k: NETWORK SLEEP -> AWAKE
[ 237.161850] Rx A-MPDU request on tid 0 result 0
[ 237.246151] ath9k: Set HW RX filter: 0x607
[ 237.250758] Open BA session requested for 00:22:6b:56:fd:e8 tid 6
[ 237.250807] activated addBA response timer on tid 6
[ 237.254103] switched off addBA timer for tid 6
[ 237.254111] Aggregation is on for tid 6
[ 237.512023] ath9k: AWAKE -> NETWORK SLEEP
[ 237.561870] ath9k: NETWORK SLEEP -> AWAKE
[ 237.567906] ath9k: AWAKE -> NETWORK SLEEP
[ 237.609757] ath9k: NETWORK SLEEP -> AWAKE
[ 237.761536] ath9k: AWAKE -> NETWORK SLEEP
[ 237.766668] ath9k: NETWORK SLEEP -> AWAKE
[ 237.773174] ath9k: AWAKE -> NETWORK SLEEP
[ 237.860751] ath9k: NETWORK SLEEP -> AWAKE
[ 237.990912] ath9k: AWAKE -> NETWORK SLEEP
[ 238.060984] ath9k: NETWORK SLEEP -> AWAKE
[ 238.247736] ath9k: AWAKE -> NETWORK SLEEP
[ 238.278694] ath9k: NETWORK SLEEP -> AWAKE
[ 238.288052] ath9k: AWAKE -> NETWORK SLEEP
[ 238.302049] wlan0: no IPv6 routers present
[ 238.346606] ath9k: NETWORK SLEEP -> AWAKE
[ 238.726554] ath9k: AWAKE -> NETWORK SLEEP
[ 238.790756] ath9k: NETWORK SLEEP -> AWAKE
[ 238.798264] ath9k: AWAKE -> NETWORK SLEEP
[ 238.893151] ath9k: NETWORK SLEEP -> AWAKE
[ 238.899188] ath9k: AWAKE -> NETWORK SLEEP
[ 238.995545] ath9k: NETWORK SLEEP -> AWAKE
[ 239.001594] ath9k: AWAKE -> NETWORK SLEEP
[ 239.097971] ath9k: NETWORK SLEEP -> AWAKE
[ 239.105098] ath9k: AWAKE -> NETWORK SLEEP
[ 239.124090] ath9k: NETWORK SLEEP -> AWAKE
[ 239.321395] ath9k: AWAKE -> NETWORK SLEEP
[ 239.405180] ath9k: NETWORK SLEEP -> AWAKE
[ 239.414369] ath9k: AWAKE -> NETWORK SLEEP
[ 239.507579] ath9k: NETWORK SLEEP -> AWAKE
[ 239.513625] ath9k: AWAKE -> NETWORK SLEEP
[ 239.609999] ath9k: NETWORK SLEEP -> AWAKE
[ 239.617122] ath9k: AWAKE -> NETWORK SLEEP
[ 239.712397] ath9k: NETWORK SLEEP -> AWAKE
[ 239.720678] ath9k: AWAKE -> NETWORK SLEEP
[ 239.814789] ath9k: NETWORK SLEEP -> AWAKE
[ 239.824492] ath9k: AWAKE -> NETWORK SLEEP
[ 239.917215] ath9k: NETWORK SLEEP -> AWAKE
[ 239.923244] ath9k: AWAKE -> NETWORK SLEEP
[ 240.019608] ath9k: NETWORK SLEEP -> AWAKE
[ 240.130542] ath9k: AWAKE -> NETWORK SLEEP
[ 240.224429] ath9k: NETWORK SLEEP -> AWAKE
[ 240.230466] ath9k: AWAKE -> NETWORK SLEEP
[ 240.326823] ath9k: NETWORK SLEEP -> AWAKE
[ 240.332868] ath9k: AWAKE -> NETWORK SLEEP
[ 240.348444] ath9k: NETWORK SLEEP -> AWAKE
[ 240.594660] ath9k: AWAKE -> NETWORK SLEEP
[ 240.595764] ath9k: NETWORK SLEEP -> AWAKE
[ 240.595848] ath9k: AWAKE -> NETWORK SLEEP
[ 240.628964] ath9k: NETWORK SLEEP -> AWAKE
[ 240.629062] ath9k: AWAKE -> NETWORK SLEEP
[ 240.629104] ath9k: NETWORK SLEEP -> AWAKE
[ 240.629182] ath9k: AWAKE -> NETWORK SLEEP
[ 240.634032] ath9k: NETWORK SLEEP -> AWAKE
[ 240.887286] ath9k: AWAKE -> NETWORK SLEEP
[ 240.941281] ath9k: NETWORK SLEEP -> AWAKE
[ 240.947301] ath9k: AWAKE -> NETWORK SLEEP
[ 241.043673] ath9k: NETWORK SLEEP -> AWAKE
[ 241.050536] ath9k: AWAKE -> NETWORK SLEEP
[ 241.146068] ath9k: NETWORK SLEEP -> AWAKE
[ 241.157875] ath9k: AWAKE -> NETWORK SLEEP
[ 241.187352] ath9k: NETWORK SLEEP -> AWAKE
[ 241.349573] ath9k: AWAKE -> NETWORK SLEEP
[ 241.350871] ath9k: NETWORK SLEEP -> AWAKE
[ 241.459328] ath9k: AWAKE -> NETWORK SLEEP
[ 241.555705] ath9k: NETWORK SLEEP -> AWAKE
[ 241.666106] ath9k: AWAKE -> NETWORK SLEEP
[ 241.745084] ath9k: NETWORK SLEEP -> AWAKE
[ 241.971677] ath9k: AWAKE -> NETWORK SLEEP
[ 242.067739] ath9k: NETWORK SLEEP -> AWAKE
[ 242.073781] ath9k: AWAKE -> NETWORK SLEEP
[ 242.170131] ath9k: NETWORK SLEEP -> AWAKE
[ 242.176647] ath9k: AWAKE -> NETWORK SLEEP
[ 242.272551] ath9k: NETWORK SLEEP -> AWAKE
[ 242.278906] ath9k: AWAKE -> NETWORK SLEEP
[ 242.374962] ath9k: NETWORK SLEEP -> AWAKE
[ 242.394167] ath9k: AWAKE -> NETWORK SLEEP
[ 242.477343] ath9k: NETWORK SLEEP -> AWAKE
[ 242.585884] ath9k: AWAKE -> NETWORK SLEEP
[ 242.682160] ath9k: NETWORK SLEEP -> AWAKE
[ 242.688191] ath9k: AWAKE -> NETWORK SLEEP
[ 242.747363] ath9k: NETWORK SLEEP -> AWAKE
[ 242.883222] ath9k: AWAKE -> NETWORK SLEEP
[ 242.886979] ath9k: NETWORK SLEEP -> AWAKE
[ 242.893011] ath9k: AWAKE -> NETWORK SLEEP
[ 242.989372] ath9k: NETWORK SLEEP -> AWAKE
[ 242.995406] ath9k: AWAKE -> NETWORK SLEEP
[ 243.091801] ath9k: NETWORK SLEEP -> AWAKE
[ 243.097883] ath9k: AWAKE -> NETWORK SLEEP
[ 243.114354] ath9k: NETWORK SLEEP -> AWAKE
[ 243.240232] ath9k: AWAKE -> NETWORK SLEEP
[ 243.296588] ath9k: NETWORK SLEEP -> AWAKE
[ 243.302634] ath9k: AWAKE -> NETWORK SLEEP
[ 243.399012] ath9k: NETWORK SLEEP -> AWAKE
[ 243.405119] ath9k: AWAKE -> NETWORK SLEEP
[ 243.501405] ath9k: NETWORK SLEEP -> AWAKE
[ 243.714300] ath9k: AWAKE -> NETWORK SLEEP
[ 243.754416] ath9k: NETWORK SLEEP -> AWAKE
[ 243.878344] ath9k: AWAKE -> NETWORK SLEEP
[ 243.911050] ath9k: NETWORK SLEEP -> AWAKE
[ 243.918049] ath9k: AWAKE -> NETWORK SLEEP
[ 244.013447] ath9k: NETWORK SLEEP -> AWAKE
[ 244.020296] ath9k: AWAKE -> NETWORK SLEEP
[ 244.115844] ath9k: NETWORK SLEEP -> AWAKE
[ 244.224376] ath9k: AWAKE -> NETWORK SLEEP
[ 244.320663] ath9k: NETWORK SLEEP -> AWAKE
[ 244.531612] ath9k: AWAKE -> NETWORK SLEEP
[ 244.627874] ath9k: NETWORK SLEEP -> AWAKE
[ 244.637811] ath9k: AWAKE -> NETWORK SLEEP
[ 244.730296] ath9k: NETWORK SLEEP -> AWAKE
[ 244.736431] ath9k: AWAKE -> NETWORK SLEEP
[ 244.756146] ath9k: NETWORK SLEEP -> AWAKE
[ 244.861664] ath9k: AWAKE -> NETWORK SLEEP
[ 244.935088] ath9k: NETWORK SLEEP -> AWAKE
[ 244.945855] ath9k: AWAKE -> NETWORK SLEEP
[ 245.037509] ath9k: NETWORK SLEEP -> AWAKE
[ 245.044897] ath9k: AWAKE -> NETWORK SLEEP
[ 245.139905] ath9k: NETWORK SLEEP -> AWAKE
[ 245.248343] ath9k: AWAKE -> NETWORK SLEEP
[ 245.344726] ath9k: NETWORK SLEEP -> AWAKE
[ 245.350755] ath9k: AWAKE -> NETWORK SLEEP
[ 245.447116] ath9k: NETWORK SLEEP -> AWAKE
[ 245.453151] ath9k: AWAKE -> NETWORK SLEEP
[ 245.549544] ath9k: NETWORK SLEEP -> AWAKE
[ 245.555803] ath9k: AWAKE -> NETWORK SLEEP
[ 245.651936] ath9k: NETWORK SLEEP -> AWAKE
[ 245.666568] ath9k: AWAKE -> NETWORK SLEEP
[ 245.754327] ath9k: NETWORK SLEEP -> AWAKE
[ 245.925685] ath9k: AWAKE -> NETWORK SLEEP
[ 245.959149] ath9k: NETWORK SLEEP -> AWAKE
[ 245.966223] ath9k: AWAKE -> NETWORK SLEEP
[ 246.061575] ath9k: NETWORK SLEEP -> AWAKE
[ 246.068154] ath9k: AWAKE -> NETWORK SLEEP
[ 246.163974] ath9k: NETWORK SLEEP -> AWAKE
[ 246.170608] ath9k: AWAKE -> NETWORK SLEEP
[ 246.266363] ath9k: NETWORK SLEEP -> AWAKE
[ 246.272511] ath9k: AWAKE -> NETWORK SLEEP
[ 246.368790] ath9k: NETWORK SLEEP -> AWAKE
[ 246.380986] ath9k: AWAKE -> NETWORK SLEEP
[ 246.471185] ath9k: NETWORK SLEEP -> AWAKE
[ 246.477750] ath9k: AWAKE -> NETWORK SLEEP
[ 246.573580] ath9k: NETWORK SLEEP -> AWAKE
[ 246.682024] ath9k: AWAKE -> NETWORK SLEEP
[ 246.759409] ath9k: NETWORK SLEEP -> AWAKE
[ 246.967195] ath9k: AWAKE -> NETWORK SLEEP
[ 246.983216] ath9k: NETWORK SLEEP -> AWAKE
[ 246.992405] ath9k: AWAKE -> NETWORK SLEEP
[ 247.085612] ath9k: NETWORK SLEEP -> AWAKE
[ 247.093153] ath9k: AWAKE -> NETWORK SLEEP
[ 247.188037] ath9k: NETWORK SLEEP -> AWAKE
[ 247.198612] ath9k: AWAKE -> NETWORK SLEEP
[ 247.290432] ath9k: NETWORK SLEEP -> AWAKE
[ 247.296463] ath9k: AWAKE -> NETWORK SLEEP
[ 247.392821] ath9k: NETWORK SLEEP -> AWAKE
[ 247.398874] ath9k: AWAKE -> NETWORK SLEEP
[ 247.495250] ath9k: NETWORK SLEEP -> AWAKE
[ 247.501426] ath9k: AWAKE -> NETWORK SLEEP
[ 247.597636] ath9k: NETWORK SLEEP -> AWAKE
[ 247.607789] ath9k: AWAKE -> NETWORK SLEEP
[ 247.700061] ath9k: NETWORK SLEEP -> AWAKE
[ 247.706663] ath9k: AWAKE -> NETWORK SLEEP
[ 247.760163] ath9k: NETWORK SLEEP -> AWAKE
[ 247.935376] ath9k: AWAKE -> NETWORK SLEEP
[ 248.007275] ath9k: NETWORK SLEEP -> AWAKE
[ 248.019496] ath9k: AWAKE -> NETWORK SLEEP
[ 248.109678] ath9k: NETWORK SLEEP -> AWAKE
[ 248.116733] ath9k: AWAKE -> NETWORK SLEEP
[ 248.212057] ath9k: NETWORK SLEEP -> AWAKE
[ 248.218163] ath9k: AWAKE -> NETWORK SLEEP
[ 248.314489] ath9k: NETWORK SLEEP -> AWAKE
[ 248.322736] ath9k: AWAKE -> NETWORK SLEEP
[ 248.416888] ath9k: NETWORK SLEEP -> AWAKE
[ 248.422929] ath9k: AWAKE -> NETWORK SLEEP
[ 248.519316] ath9k: NETWORK SLEEP -> AWAKE
[ 248.525617] ath9k: AWAKE -> NETWORK SLEEP
[ 248.621708] ath9k: NETWORK SLEEP -> AWAKE
[ 248.894350] ath9k: AWAKE -> NETWORK SLEEP
[ 248.894435] ath9k: NETWORK SLEEP -> AWAKE
[ 248.894515] ath9k: AWAKE -> NETWORK SLEEP
[ 248.909766] ath9k: NETWORK SLEEP -> AWAKE
[ 248.909856] ath9k: AWAKE -> NETWORK SLEEP
[ 248.909892] ath9k: NETWORK SLEEP -> AWAKE
[ 248.909966] ath9k: AWAKE -> NETWORK SLEEP
[ 248.925353] ath9k: NETWORK SLEEP -> AWAKE
[ 248.925442] ath9k: AWAKE -> NETWORK SLEEP
[ 248.926743] ath9k: NETWORK SLEEP -> AWAKE
[ 248.926824] ath9k: AWAKE -> NETWORK SLEEP
[ 248.928906] ath9k: NETWORK SLEEP -> AWAKE
[ 248.934618] ath9k: AWAKE -> NETWORK SLEEP
[ 248.934894] ath9k: NETWORK SLEEP -> AWAKE
[ 248.934969] ath9k: AWAKE -> NETWORK SLEEP
[ 248.935414] ath9k: NETWORK SLEEP -> AWAKE
[ 248.935501] ath9k: AWAKE -> NETWORK SLEEP
[ 248.935547] ath9k: NETWORK SLEEP -> AWAKE
[ 248.935621] ath9k: AWAKE -> NETWORK SLEEP
[ 248.935872] ath9k: NETWORK SLEEP -> AWAKE
[ 248.935952] ath9k: AWAKE -> NETWORK SLEEP
[ 248.935988] ath9k: NETWORK SLEEP -> AWAKE
[ 248.936088] ath9k: AWAKE -> NETWORK SLEEP
[ 248.936097] ath9k: NETWORK SLEEP -> AWAKE
[ 248.936198] ath9k: AWAKE -> NETWORK SLEEP
[ 248.936210] ath9k: NETWORK SLEEP -> AWAKE
[ 248.936292] ath9k: AWAKE -> NETWORK SLEEP
[ 248.936692] ath9k: NETWORK SLEEP -> AWAKE
[ 248.936819] ath9k: AWAKE -> NETWORK SLEEP
[ 248.940131] ath9k: NETWORK SLEEP -> AWAKE
[ 249.061727] ath9k: AWAKE -> NETWORK SLEEP
[ 249.133741] ath9k: NETWORK SLEEP -> AWAKE
[ 249.142554] ath9k: AWAKE -> NETWORK SLEEP
[ 249.236138] ath9k: NETWORK SLEEP -> AWAKE
[ 249.242164] ath9k: AWAKE -> NETWORK SLEEP
[ 249.338563] ath9k: NETWORK SLEEP -> AWAKE
[ 249.344678] ath9k: AWAKE -> NETWORK SLEEP
[ 249.440959] ath9k: NETWORK SLEEP -> AWAKE
[ 249.447605] ath9k: AWAKE -> NETWORK SLEEP
[ 249.543348] ath9k: NETWORK SLEEP -> AWAKE
[ 249.549393] ath9k: AWAKE -> NETWORK SLEEP
[ 249.577650] PM: Syncing filesystems ...
[ 249.645775] ath9k: NETWORK SLEEP -> AWAKE
[ 249.651822] ath9k: AWAKE -> NETWORK SLEEP
[ 249.677281] done.
[ 249.677291] PM: Preparing system for mem sleep
[ 249.748159] ath9k: NETWORK SLEEP -> AWAKE
[ 249.754256] ath9k: AWAKE -> NETWORK SLEEP
[ 249.765132] ath9k: NETWORK SLEEP -> AWAKE
[ 249.824923] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 249.826762] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 249.826830] PM: Entering mem sleep
[ 249.826853] Suspending console(s) (use no_console_suspend to debug)
[ 249.832057] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 249.832077] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 249.832110] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 249.832130] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 6
[ 249.832141] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 6
[ 249.832166] ath9k: Detach Interface
[ 249.834435] ath9k: AWAKE -> FULL-SLEEP
[ 249.834446] ath9k: Driver halt
[ 249.858079] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 249.858457] sd 0:0:0:0: [sda] Stopping disk
[ 250.781437] ath9k 0000:01:00.0: PCI INT A disabled
[ 250.805619] ACPI handle has no context!
[ 250.805632] atl1c 0000:02:00.0: PME# disabled
[ 250.805645] atl1c 0000:02:00.0: PCI INT A disabled
[ 250.805654] ACPI handle has no context!
[ 250.849209] ata6: port disabled. ignoring.
[ 250.849279] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 250.849297] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 250.849310] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 250.849320] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 250.849331] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 250.849342] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 250.867856] i915 0000:00:02.0: PCI INT A disabled
[ 250.878415] ehci_hcd 0000:00:1d.7: PME# disabled
[ 250.889462] ACPI: Preparing to enter system sleep state S3
[ 250.979768] Disabling non-boot CPUs ...
[ 251.083028] CPU 1 is now offline
[ 251.083033] SMP alternatives: switching to UP code
[ 251.087065] CPU1 is down
[ 251.087088] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 251.087088] Back to C!
[ 251.087088] Enabling non-boot CPUs ...
[ 251.087088] SMP alternatives: switching to SMP code
[ 251.090663] Booting processor 1 APIC 0x1 ip 0x6000
[ 251.086421] Initializing CPU#1
[ 251.086421] Calibrating delay using timer specific routine.. 3329.63 BogoMIPS (lpj=1664818)
[ 251.086421] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 251.086421] CPU: L2 cache: 512K
[ 251.086421] CPU: Physical Processor ID: 0
[ 251.086421] CPU: Processor Core ID: 0
[ 251.086421] mce: CPU supports 5 MCE banks
[ 251.086421] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 251.161902] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 251.162270] Switched to high resolution mode on CPU 1
[ 251.167037] CPU1 is up
[ 251.167044] ACPI: Waking up from system sleep state S3
[ 251.513515] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x7 (was 0xf0, writing 0x200000f0)
[ 251.513536] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 251.513622] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 251.513697] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x7 (was 0xf0, writing 0x200000f0)
[ 251.513717] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 251.513790] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 251.513834] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 251.513877] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 251.513920] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 251.513973] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 251.513998] ehci_hcd 0000:00:1d.7: PME# disabled
[ 251.514185] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 251.891087] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 251.891096] i915 0000:00:02.0: setting latency timer to 64
[ 251.952686] [drm] LVDS-8: set mode 1024x600 e
[ 251.972895] pci 0000:00:02.1: PME# disabled
[ 251.972904] pci 0000:00:1b.0: PME# disabled
[ 251.972931] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 251.972941] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 251.972970] usb usb2: root hub lost power or was reset
[ 251.972995] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 251.973017] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 251.973044] usb usb3: root hub lost power or was reset
[ 251.973069] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 251.973079] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 251.973105] usb usb4: root hub lost power or was reset
[ 251.973129] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 251.973139] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 251.973165] usb usb5: root hub lost power or was reset
[ 251.973202] ehci_hcd 0000:00:1d.7: PME# disabled
[ 251.973211] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 251.973220] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 251.973259] pci 0000:00:1e.0: setting latency timer to 64
[ 251.973280] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 251.973295] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 251.974930] ata6: port disabled. ignoring.
[ 251.974958] ahci 0000:00:1f.2: setting latency timer to 64
[ 251.975038] atl1c 0000:02:00.0: PME# disabled
[ 251.975046] atl1c 0000:02:00.0: PME# disabled
[ 252.000065] Clocksource tsc unstable (delta = -500035026 ns)
[ 252.038615] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 252.038696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 252.280096] ata3: SATA link down (SStatus 0 SControl 300)
[ 252.510608] sd 0:0:0:0: [sda] Starting disk
[ 252.535086] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 252.537198] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 252.539942] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 252.540377] ata1.00: configured for UDMA/133
[ 252.551076] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0xf t4
[ 252.551085] ata1: irq_stat 0x00400040, connection status changed
[ 252.551103] ata1: hard resetting link
[ 253.274077] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 253.363507] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 253.366212] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 253.366627] ata1.00: configured for UDMA/133
[ 253.366637] ata1: EH complete
[ 253.525070] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 253.805064] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 254.521068] ath9k: Starting driver with initial channel: 2437 MHz
[ 254.522086] ath9k: FULL-SLEEP -> AWAKE
[ 254.533094] ath9k: ah->misc_mode 0x4
[ 254.535214] ath9k: Attach a VIF of type: 2
[ 254.535248] ath9k: Set channel: 2437 MHz
[ 254.535252] ath9k: tx chmask: 1, rx chmask: 1
[ 254.535373] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 254.541929] ath9k: ah->misc_mode 0x4
[ 254.544052] ath9k: Set HW RX filter: 0x607
[ 254.544058] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 254.544065] ath9k: BSS Changed PREAMBLE 1
[ 254.544068] ath9k: BSS Changed CTS PROT 0
[ 254.544072] ath9k: BSS Changed ASSOC 1
[ 254.544076] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 254.546454] PM: Finishing wakeup.
[ 254.546458] Restarting tasks ... done.
[ 254.589051] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 254.589095] activated addBA response timer on tid 0
[ 254.615144] Rx A-MPDU request on tid 0 result 0
[ 254.717357] switched off addBA timer for tid 0
[ 254.717366] Aggregation is on for tid 0
[ 254.718297] switched off addBA timer for tid 0
[ 255.170649] ath9k: AWAKE -> NETWORK SLEEP
[ 255.259366] ath9k: NETWORK SLEEP -> AWAKE
[ 255.267232] ath9k: AWAKE -> NETWORK SLEEP
[ 255.362310] ath9k: NETWORK SLEEP -> AWAKE
[ 255.367505] ath9k: AWAKE -> NETWORK SLEEP
[ 255.463747] ath9k: NETWORK SLEEP -> AWAKE
[ 255.472573] ath9k: AWAKE -> NETWORK SLEEP
[ 255.566148] ath9k: NETWORK SLEEP -> AWAKE
[ 255.572445] ath9k: AWAKE -> NETWORK SLEEP
[ 255.579315] ath9k: NETWORK SLEEP -> AWAKE
[ 255.716166] ath9k: AWAKE -> NETWORK SLEEP
[ 255.770968] ath9k: NETWORK SLEEP -> AWAKE
[ 255.914369] ath9k: AWAKE -> NETWORK SLEEP
[ 255.975786] ath9k: NETWORK SLEEP -> AWAKE
[ 255.989251] ath9k: AWAKE -> NETWORK SLEEP
[ 256.078177] ath9k: NETWORK SLEEP -> AWAKE
[ 256.089350] ath9k: AWAKE -> NETWORK SLEEP
[ 256.180575] ath9k: NETWORK SLEEP -> AWAKE
[ 256.186818] ath9k: AWAKE -> NETWORK SLEEP
[ 256.282999] ath9k: NETWORK SLEEP -> AWAKE
[ 256.289584] ath9k: AWAKE -> NETWORK SLEEP
[ 256.385395] ath9k: NETWORK SLEEP -> AWAKE
[ 256.392602] ath9k: AWAKE -> NETWORK SLEEP
[ 256.487815] ath9k: NETWORK SLEEP -> AWAKE
[ 256.495918] ath9k: AWAKE -> NETWORK SLEEP
[ 256.581243] ath9k: NETWORK SLEEP -> AWAKE
[ 256.752936] ath9k: AWAKE -> NETWORK SLEEP
[ 256.795032] ath9k: NETWORK SLEEP -> AWAKE
[ 256.808386] ath9k: AWAKE -> NETWORK SLEEP
[ 256.897427] ath9k: NETWORK SLEEP -> AWAKE
[ 256.905851] ath9k: AWAKE -> NETWORK SLEEP
[ 256.999823] ath9k: NETWORK SLEEP -> AWAKE
[ 257.007478] ath9k: AWAKE -> NETWORK SLEEP
[ 257.102240] ath9k: NETWORK SLEEP -> AWAKE
[ 257.109563] ath9k: AWAKE -> NETWORK SLEEP
[ 257.204636] ath9k: NETWORK SLEEP -> AWAKE
[ 257.218321] ath9k: AWAKE -> NETWORK SLEEP
[ 257.307067] ath9k: NETWORK SLEEP -> AWAKE
[ 257.320752] ath9k: AWAKE -> NETWORK SLEEP
[ 257.409459] ath9k: NETWORK SLEEP -> AWAKE
[ 257.415526] ath9k: AWAKE -> NETWORK SLEEP
[ 257.511849] ath9k: NETWORK SLEEP -> AWAKE
[ 257.522702] ath9k: AWAKE -> NETWORK SLEEP
[ 257.583206] ath9k: NETWORK SLEEP -> AWAKE
[ 257.736613] ath9k: AWAKE -> NETWORK SLEEP
[ 257.819066] ath9k: NETWORK SLEEP -> AWAKE
[ 257.825107] ath9k: AWAKE -> NETWORK SLEEP
[ 257.921492] ath9k: NETWORK SLEEP -> AWAKE
[ 258.031682] ath9k: AWAKE -> NETWORK SLEEP
[ 258.126312] ath9k: NETWORK SLEEP -> AWAKE
[ 258.133191] ath9k: AWAKE -> NETWORK SLEEP
[ 258.228705] ath9k: NETWORK SLEEP -> AWAKE
[ 258.234750] ath9k: AWAKE -> NETWORK SLEEP
[ 258.331101] ath9k: NETWORK SLEEP -> AWAKE
[ 258.439544] ath9k: AWAKE -> NETWORK SLEEP
[ 258.535916] ath9k: NETWORK SLEEP -> AWAKE
[ 258.545161] ath9k: AWAKE -> NETWORK SLEEP
[ 258.585117] ath9k: NETWORK SLEEP -> AWAKE
[ 258.800412] ath9k: AWAKE -> NETWORK SLEEP
[ 258.843128] ath9k: NETWORK SLEEP -> AWAKE
[ 258.854426] ath9k: AWAKE -> NETWORK SLEEP
[ 258.945557] ath9k: NETWORK SLEEP -> AWAKE
[ 259.056202] ath9k: AWAKE -> NETWORK SLEEP
[ 259.150342] ath9k: NETWORK SLEEP -> AWAKE
[ 259.164096] ath9k: AWAKE -> NETWORK SLEEP
[ 259.252754] ath9k: NETWORK SLEEP -> AWAKE
[ 259.268592] ath9k: AWAKE -> NETWORK SLEEP
[ 259.355152] ath9k: NETWORK SLEEP -> AWAKE
[ 259.364883] ath9k: AWAKE -> NETWORK SLEEP
[ 259.457558] ath9k: NETWORK SLEEP -> AWAKE
[ 259.463747] ath9k: AWAKE -> NETWORK SLEEP
[ 259.559975] ath9k: NETWORK SLEEP -> AWAKE
[ 259.566046] ath9k: AWAKE -> NETWORK SLEEP
[ 259.586374] ath9k: NETWORK SLEEP -> AWAKE
[ 259.708679] ath9k: AWAKE -> NETWORK SLEEP
[ 259.764796] ath9k: NETWORK SLEEP -> AWAKE
[ 259.775523] ath9k: AWAKE -> NETWORK SLEEP
[ 259.867193] ath9k: NETWORK SLEEP -> AWAKE
[ 259.873841] ath9k: AWAKE -> NETWORK SLEEP
[ 259.969575] ath9k: NETWORK SLEEP -> AWAKE
[ 259.976974] ath9k: AWAKE -> NETWORK SLEEP
[ 260.072013] ath9k: NETWORK SLEEP -> AWAKE
[ 260.078410] ath9k: AWAKE -> NETWORK SLEEP
[ 260.174434] ath9k: NETWORK SLEEP -> AWAKE
[ 260.182442] ath9k: AWAKE -> NETWORK SLEEP
[ 260.276805] ath9k: NETWORK SLEEP -> AWAKE
[ 260.385257] ath9k: AWAKE -> NETWORK SLEEP
[ 260.481624] ath9k: NETWORK SLEEP -> AWAKE
[ 260.489597] ath9k: AWAKE -> NETWORK SLEEP
[ 260.493661] PM: Syncing filesystems ...
[ 260.584050] ath9k: NETWORK SLEEP -> AWAKE
[ 260.702871] ath9k: AWAKE -> NETWORK SLEEP
[ 260.788838] ath9k: NETWORK SLEEP -> AWAKE
[ 260.800819] ath9k: AWAKE -> NETWORK SLEEP
[ 260.891260] ath9k: NETWORK SLEEP -> AWAKE
[ 260.900646] ath9k: AWAKE -> NETWORK SLEEP
[ 260.993657] ath9k: NETWORK SLEEP -> AWAKE
[ 261.031443] done.
[ 261.031450] PM: Preparing system for mem sleep
[ 261.102081] ath9k: AWAKE -> NETWORK SLEEP
[ 261.177037] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 261.178420] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 261.178507] PM: Entering mem sleep
[ 261.178529] Suspending console(s) (use no_console_suspend to debug)
[ 261.183334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 261.183354] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 261.183393] ath9k:
[ 261.183402] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 261.183411] NETWORK SLEEP -> AWAKE
[ 261.183507] ath9k: Detach Interface
[ 261.185808] ath9k: AWAKE -> FULL-SLEEP
[ 261.185818] ath9k: Driver halt
[ 261.209077] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 261.209436] sd 0:0:0:0: [sda] Stopping disk
[ 262.135172] ath9k 0000:01:00.0: PCI INT A disabled
[ 262.159620] ACPI handle has no context!
[ 262.159632] atl1c 0000:02:00.0: PME# disabled
[ 262.159641] ACPI handle has no context!
[ 262.203159] ata6: port disabled. ignoring.
[ 262.203249] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 262.203267] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 262.203279] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 262.203290] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 262.203301] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 262.203311] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 262.217293] i915 0000:00:02.0: PCI INT A disabled
[ 262.228409] ehci_hcd 0000:00:1d.7: PME# disabled
[ 262.239465] ACPI: Preparing to enter system sleep state S3
[ 262.323768] Disabling non-boot CPUs ...
[ 262.326104] CPU 1 is now offline
[ 262.326110] SMP alternatives: switching to UP code
[ 262.330136] CPU1 is down
[ 262.330160] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 262.330160] Back to C!
[ 262.330160] Enabling non-boot CPUs ...
[ 262.330160] SMP alternatives: switching to SMP code
[ 262.333739] Booting processor 1 APIC 0x1 ip 0x6000
[ 262.329484] Initializing CPU#1
[ 262.329484] Calibrating delay using timer specific routine.. 3329.65 BogoMIPS (lpj=1664826)
[ 262.329484] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 262.329484] CPU: L2 cache: 512K
[ 262.329484] CPU: Physical Processor ID: 0
[ 262.329484] CPU: Processor Core ID: 0
[ 262.329484] mce: CPU supports 5 MCE banks
[ 262.329484] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 262.404875] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 262.405269] Switched to high resolution mode on CPU 1
[ 262.408033] CPU1 is up
[ 262.408040] ACPI: Waking up from system sleep state S3
[ 262.754531] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 262.754619] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 262.754703] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 262.754776] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 262.754820] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 262.754863] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 262.754906] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 262.754959] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 262.754984] ehci_hcd 0000:00:1d.7: PME# disabled
[ 262.755170] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 263.119684] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 263.119693] i915 0000:00:02.0: setting latency timer to 64
[ 263.181289] [drm] LVDS-8: set mode 1024x600 e
[ 263.201499] pci 0000:00:02.1: PME# disabled
[ 263.201508] pci 0000:00:1b.0: PME# disabled
[ 263.201536] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 263.201546] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 263.201575] usb usb2: root hub lost power or was reset
[ 263.201600] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 263.201609] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 263.201636] usb usb3: root hub lost power or was reset
[ 263.201660] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 263.201670] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 263.201696] usb usb4: root hub lost power or was reset
[ 263.201720] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 263.201730] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 263.201756] usb usb5: root hub lost power or was reset
[ 263.201793] ehci_hcd 0000:00:1d.7: PME# disabled
[ 263.201801] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 263.201811] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 263.201845] pci 0000:00:1e.0: setting latency timer to 64
[ 263.201861] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 263.201869] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 263.203529] ahci 0000:00:1f.2: setting latency timer to 64
[ 263.203606] atl1c 0000:02:00.0: PME# disabled
[ 263.203618] atl1c 0000:02:00.0: PME# disabled
[ 263.205173] ata6: port disabled. ignoring.
[ 263.266615] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 263.266697] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 263.509085] ata3: SATA link down (SStatus 0 SControl 300)
[ 263.744225] sd 0:0:0:0: [sda] Starting disk
[ 263.815074] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 263.817183] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 263.819960] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 263.820379] ata1.00: configured for UDMA/133
[ 263.831076] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x9 t4
[ 263.831085] ata1: irq_stat 0x00000040, connection status changed
[ 263.835194] ata1.00: configured for UDMA/133
[ 263.835203] ata1: EH complete
[ 263.990069] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 264.270065] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 264.985093] ath9k: Starting driver with initial channel: 2437 MHz
[ 264.986112] ath9k: FULL-SLEEP -> AWAKE
[ 264.997044] ath9k: ah->misc_mode 0x4
[ 264.999170] ath9k: Attach a VIF of type: 2
[ 264.999204] ath9k: Set channel: 2437 MHz
[ 264.999208] ath9k: tx chmask: 1, rx chmask: 1
[ 264.999329] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 265.005872] ath9k: ah->misc_mode 0x4
[ 265.007985] ath9k: Set HW RX filter: 0x607
[ 265.007991] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 265.007998] ath9k: BSS Changed PREAMBLE 1
[ 265.008015] ath9k: BSS Changed CTS PROT 0
[ 265.008019] ath9k: BSS Changed ASSOC 1
[ 265.008022] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 265.010482] PM: Finishing wakeup.
[ 265.010486] Restarting tasks ... done.
[ 265.073219] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 265.073260] activated addBA response timer on tid 0
[ 265.079559] Rx A-MPDU request on tid 0 result 0
[ 265.080333] switched off addBA timer for tid 0
[ 265.080340] Aggregation is on for tid 0
[ 265.183979] ath9k: AWAKE -> NETWORK SLEEP
[ 265.216135] ath9k: NETWORK SLEEP -> AWAKE
[ 265.257061] ath9k: AWAKE -> NETWORK SLEEP
[ 265.351346] ath9k: NETWORK SLEEP -> AWAKE
[ 265.358516] ath9k: AWAKE -> NETWORK SLEEP
[ 265.453746] ath9k: NETWORK SLEEP -> AWAKE
[ 265.566082] ath9k: AWAKE -> NETWORK SLEEP
[ 265.658575] ath9k: NETWORK SLEEP -> AWAKE
[ 265.664594] ath9k: AWAKE -> NETWORK SLEEP
[ 265.761426] ath9k: NETWORK SLEEP -> AWAKE
[ 265.766991] ath9k: AWAKE -> NETWORK SLEEP
[ 265.863359] ath9k: NETWORK SLEEP -> AWAKE
[ 265.870216] ath9k: AWAKE -> NETWORK SLEEP
[ 265.965785] ath9k: NETWORK SLEEP -> AWAKE
[ 266.155285] ath9k: AWAKE -> NETWORK SLEEP
[ 266.170609] ath9k: NETWORK SLEEP -> AWAKE
[ 266.176629] ath9k: AWAKE -> NETWORK SLEEP
[ 266.273004] ath9k: NETWORK SLEEP -> AWAKE
[ 266.290227] ath9k: AWAKE -> NETWORK SLEEP
[ 266.375397] ath9k: NETWORK SLEEP -> AWAKE
[ 266.390555] ath9k: AWAKE -> NETWORK SLEEP
[ 266.477821] ath9k: NETWORK SLEEP -> AWAKE
[ 266.483838] ath9k: AWAKE -> NETWORK SLEEP
[ 266.580212] ath9k: NETWORK SLEEP -> AWAKE
[ 266.592311] ath9k: AWAKE -> NETWORK SLEEP
[ 266.682609] ath9k: NETWORK SLEEP -> AWAKE
[ 266.689742] ath9k: AWAKE -> NETWORK SLEEP
[ 266.785034] ath9k: NETWORK SLEEP -> AWAKE
[ 266.791060] ath9k: AWAKE -> NETWORK SLEEP
[ 266.887430] ath9k: NETWORK SLEEP -> AWAKE
[ 266.893463] ath9k: AWAKE -> NETWORK SLEEP
[ 266.989851] ath9k: NETWORK SLEEP -> AWAKE
[ 266.996265] ath9k: AWAKE -> NETWORK SLEEP
[ 267.041821] ath9k: NETWORK SLEEP -> AWAKE
[ 267.149699] ath9k: AWAKE -> NETWORK SLEEP
[ 267.149746] ath9k: NETWORK SLEEP -> AWAKE
[ 267.149826] ath9k: AWAKE -> NETWORK SLEEP
[ 267.156269] ath9k: NETWORK SLEEP -> AWAKE
[ 267.156401] ath9k: AWAKE -> NETWORK SLEEP
[ 267.156431] ath9k: NETWORK SLEEP -> AWAKE
[ 267.263985] ath9k: AWAKE -> NETWORK SLEEP
[ 267.297068] ath9k: NETWORK SLEEP -> AWAKE
[ 267.303088] ath9k: AWAKE -> NETWORK SLEEP
[ 267.399463] ath9k: NETWORK SLEEP -> AWAKE
[ 267.509124] ath9k: AWAKE -> NETWORK SLEEP
[ 267.604281] ath9k: NETWORK SLEEP -> AWAKE
[ 267.610935] ath9k: AWAKE -> NETWORK SLEEP
[ 267.706676] ath9k: NETWORK SLEEP -> AWAKE
[ 267.712885] ath9k: AWAKE -> NETWORK SLEEP
[ 267.809099] ath9k: NETWORK SLEEP -> AWAKE
[ 267.815119] ath9k: AWAKE -> NETWORK SLEEP
[ 267.911494] ath9k: NETWORK SLEEP -> AWAKE
[ 267.922560] ath9k: AWAKE -> NETWORK SLEEP
[ 268.013888] ath9k: NETWORK SLEEP -> AWAKE
[ 268.024162] ath9k: AWAKE -> NETWORK SLEEP
[ 268.043685] ath9k: NETWORK SLEEP -> AWAKE
[ 268.327988] ath9k: AWAKE -> NETWORK SLEEP
[ 268.423524] ath9k: NETWORK SLEEP -> AWAKE
[ 268.430287] ath9k: AWAKE -> NETWORK SLEEP
[ 268.525922] ath9k: NETWORK SLEEP -> AWAKE
[ 268.531956] ath9k: AWAKE -> NETWORK SLEEP
[ 268.628342] ath9k: NETWORK SLEEP -> AWAKE
[ 268.634355] ath9k: AWAKE -> NETWORK SLEEP
[ 268.730741] ath9k: NETWORK SLEEP -> AWAKE
[ 268.736772] ath9k: AWAKE -> NETWORK SLEEP
[ 268.833132] ath9k: NETWORK SLEEP -> AWAKE
[ 268.839698] ath9k: AWAKE -> NETWORK SLEEP
[ 268.935560] ath9k: NETWORK SLEEP -> AWAKE
[ 268.941811] ath9k: AWAKE -> NETWORK SLEEP
[ 269.037953] ath9k: NETWORK SLEEP -> AWAKE
[ 269.364463] ath9k: AWAKE -> NETWORK SLEEP
[ 269.447561] ath9k: NETWORK SLEEP -> AWAKE
[ 269.659769] ath9k: AWAKE -> NETWORK SLEEP
[ 269.667818] ath9k: NETWORK SLEEP -> AWAKE
[ 270.183772] ath9k: AWAKE -> NETWORK SLEEP
[ 270.266796] ath9k: NETWORK SLEEP -> AWAKE
[ 270.274056] ath9k: AWAKE -> NETWORK SLEEP
[ 270.369199] ath9k: NETWORK SLEEP -> AWAKE
[ 270.380323] ath9k: AWAKE -> NETWORK SLEEP
[ 270.471615] ath9k: NETWORK SLEEP -> AWAKE
[ 270.477675] ath9k: AWAKE -> NETWORK SLEEP
[ 270.574054] ath9k: NETWORK SLEEP -> AWAKE
[ 270.582421] ath9k: AWAKE -> NETWORK SLEEP
[ 270.676431] ath9k: NETWORK SLEEP -> AWAKE
[ 270.682643] ath9k: AWAKE -> NETWORK SLEEP
[ 270.778860] ath9k: NETWORK SLEEP -> AWAKE
[ 270.989686] ath9k: AWAKE -> NETWORK SLEEP
[ 271.049041] ath9k: NETWORK SLEEP -> AWAKE
[ 271.304833] PM: Syncing filesystems ... done.
[ 271.307636] PM: Preparing system for mem sleep
[ 271.399307] ath9k: AWAKE -> NETWORK SLEEP
[ 271.448580] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 271.450215] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 271.450296] PM: Entering mem sleep
[ 271.450321] Suspending console(s) (use no_console_suspend to debug)
[ 271.456054] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 271.456073] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 271.456112] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 271.456141] ath9k: Detach Interface
[ 271.456161] ath9k: NETWORK SLEEP -> AWAKE
[ 271.458525] ath9k: AWAKE -> NETWORK SLEEP
[ 271.458533] ath9k: NETWORK SLEEP -> FULL-SLEEP
[ 271.458544] ath9k:
[ 271.458547] ath9k: Driver halt
[ 271.458552] FULL-SLEEP -> AWAKE
[ 271.485081] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 271.485444] sd 0:0:0:0: [sda] Stopping disk
[ 272.348209] ath9k 0000:01:00.0: PCI INT A disabled
[ 272.372613] ACPI handle has no context!
[ 272.372624] atl1c 0000:02:00.0: PME# disabled
[ 272.372634] ACPI handle has no context!
[ 272.416210] ata6: port disabled. ignoring.
[ 272.416281] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 272.416299] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 272.416311] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 272.416321] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 272.416332] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 272.416343] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 272.430411] i915 0000:00:02.0: PCI INT A disabled
[ 272.441409] ehci_hcd 0000:00:1d.7: PME# disabled
[ 272.452467] ACPI: Preparing to enter system sleep state S3
[ 272.545771] Disabling non-boot CPUs ...
[ 272.548103] CPU 1 is now offline
[ 272.548109] SMP alternatives: switching to UP code
[ 272.552115] CPU1 is down
[ 272.552139] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 272.552139] Back to C!
[ 272.552139] Enabling non-boot CPUs ...
[ 272.552139] SMP alternatives: switching to SMP code
[ 272.555716] Booting processor 1 APIC 0x1 ip 0x6000
[ 272.551463] Initializing CPU#1
[ 272.551463] Calibrating delay using timer specific routine.. 3329.63 BogoMIPS (lpj=1664817)
[ 272.551463] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 272.551463] CPU: L2 cache: 512K
[ 272.551463] CPU: Physical Processor ID: 0
[ 272.551463] CPU: Processor Core ID: 0
[ 272.551463] mce: CPU supports 5 MCE banks
[ 272.551463] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 272.626857] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 272.627269] Switched to high resolution mode on CPU 1
[ 272.630035] CPU1 is up
[ 272.630041] ACPI: Waking up from system sleep state S3
[ 272.996533] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 272.996621] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 272.996706] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 272.996779] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 272.996823] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 272.996866] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 272.996910] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 272.996962] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 272.996988] ehci_hcd 0000:00:1d.7: PME# disabled
[ 272.997173] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 273.375286] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 273.375297] i915 0000:00:02.0: setting latency timer to 64
[ 273.436889] [drm] LVDS-8: set mode 1024x600 e
[ 273.457098] pci 0000:00:02.1: PME# disabled
[ 273.457107] pci 0000:00:1b.0: PME# disabled
[ 273.457134] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 273.457145] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 273.457173] usb usb2: root hub lost power or was reset
[ 273.457198] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 273.457208] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 273.457235] usb usb3: root hub lost power or was reset
[ 273.457266] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 273.457279] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 273.457309] usb usb4: root hub lost power or was reset
[ 273.457334] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 273.457344] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 273.457371] usb usb5: root hub lost power or was reset
[ 273.457408] ehci_hcd 0000:00:1d.7: PME# disabled
[ 273.457417] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 273.457426] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 273.457460] pci 0000:00:1e.0: setting latency timer to 64
[ 273.457476] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 273.457485] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 273.459135] ata6: port disabled. ignoring.
[ 273.459162] ahci 0000:00:1f.2: setting latency timer to 64
[ 273.459227] atl1c 0000:02:00.0: PME# disabled
[ 273.459236] atl1c 0000:02:00.0: PME# disabled
[ 273.522615] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 273.522696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 273.764086] ata3: SATA link down (SStatus 0 SControl 300)
[ 273.764099] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 273.766234] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 273.768992] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 273.769428] ata1.00: configured for UDMA/133
[ 273.780077] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0xf t4
[ 273.780086] ata1: irq_stat 0x00400040, connection status changed
[ 273.780104] ata1: hard resetting link
[ 273.993975] sd 0:0:0:0: [sda] Starting disk
[ 274.503082] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 274.585102] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 274.587713] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 274.588112] ata1.00: configured for UDMA/133
[ 274.588123] ata1: EH complete
[ 274.747070] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 275.026064] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 275.742070] ath9k: Starting driver with initial channel: 2437 MHz
[ 275.891791] ath9k: timeout (100000 us) on reg 0x7000: 0xdeadbeef & 0x00000003 != 0x00000000
[ 275.891799] ath9k: RTC stuck in MAC reset
[ 275.891803] ath9k: Chip reset failed
[ 275.891807] ath9k: Unable to reset hardware; reset status -22 (freq 2437 MHz)
[ 275.891827] ath9k: Attach a VIF of type: 2
[ 275.891867] ath9k: Set channel: 2437 MHz
[ 275.891873] ath9k: tx chmask: 1, rx chmask: 1
[ 275.891880] ath9k: Unable to set channel
[ 275.891894] ath9k: Set HW RX filter: 0x2707
[ 275.891901] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 275.891910] ath9k: BSS Changed PREAMBLE 1
[ 275.891915] ath9k: BSS Changed CTS PROT 0
[ 275.891919] ath9k: BSS Changed ASSOC 1
[ 275.891924] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 275.894481] PM: Finishing wakeup.
[ 275.894486] Restarting tasks ... done.
[ 276.835592] irq 18: nobody cared (try booting with the "irqpoll" option)
[ 276.835609] Pid: 1710, comm: Xorg Not tainted 2.6.31.4-intel-menlow #14
[ 276.835616] Call Trace:
[ 276.835636] [<c105ca3e>] __report_bad_irq+0x2e/0x6f
[ 276.835646] [<c105cb74>] note_interrupt+0xf5/0x14d
[ 276.835656] [<c105d0a4>] handle_fasteoi_irq+0x7d/0x9b
[ 276.835668] [<c10048c1>] handle_irq+0x3b/0x46
[ 276.835677] [<c1004103>] do_IRQ+0x41/0x95
[ 276.835687] [<c1003189>] common_interrupt+0x29/0x30
[ 276.835693] handlers:
[ 276.835698] [<f89a3d03>] (ath_isr+0x0/0x12f [ath9k])
[ 276.835739] Disabling IRQ #18

2009-12-23 18:33:53

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 08:54:20PM -0800, Sujith Manoharan wrote:
> Luis Rodriguez wrote:
> > Did you see the last one? It turns out its the only config option
> > passed by mac8021 I've seen so far so my commit log should change.
>
> Right, that patch should work.
> So the one I sent out and this one fixes the issue ?

Actually the last one alone fixes the issue, likely because harware is not
failing on the routines during the stop() callback when stopping harware, that
is theese guys don't fail if in NETWORK_SLEEP it seems:

ath9k_hw_disable(ah);
ath9k_hw_configpcipowersave(ah, 1, 1);
ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);

This is likely due to lack of proper documentation on our part of which
hardware blocks exactly cannot be accessed when the devices is in
NETWORK_SLEEP. But to be safe its better to just sprinkly the ps_awake
/resume calls where we do see harware being poked. If we find details
on this question though we can likely enhance power saving more
and do some operations even while in NETWORK_SLEEP.

Then as for the core of the issue -- it was not ath9k anyway, the last
patch I posted indeed fixes the issue but mac80211 drivers should not have
to worry about such issues.

As it turns out mac80211 is scheduling the dynamic_ps_disable_work work
after the driver stop() call has been called. This exposes two issues then
on mac80211. But to elaborate on those let me paste the some relevants
parts of pm.c __ieee80211_suspend():

int __ieee80211_suspend(struct ieee80211_hw *hw)
{
...
ieee80211_stop_queues_by_reason(hw,
IEEE80211_QUEUE_STOP_REASON_SUSPEND);

/* flush out all packets */
synchronize_net();

local->quiescing = true;
/* make quiescing visible to timers everywhere */
mb();

flush_workqueue(local->workqueue);
...

/* stop hardware - this must stop RX */
if (local->open_count)
ieee80211_stop_device(local);

local->suspended = true;
/* need suspended to be visible before quiescing is false */
barrier();
local->quiescing = false;

return 0;
}

The issues are as follows:

1) We stop TX and flush all packets out, and then call the driver stop().
Unfortunately there is a failed assumption that even ieee80211_xmit()
would not be called after stopping TX as __ieee80211_suspend() does
above.
2) Since ieee80211_xmit() is being called even after the driver stop()
callback it means mac80211 can potentially schedule work. Now the
new rework on the mac80211 workqueue pushes us to WARN when either
a driver or mac80211 tried to queue work onto the mac80211 workqueue
and we're suspended. A new patch from Johannes futher enhances this
to take into consideration resume so that we can allow drivers / mac80211
to queue work if we were suspended but now resuming. Even with these
checks in place I note that currently we do slip work through after
the driver stop() callback is called and before loacl->suspended is
set to true. So there seems to be a race here.

The first issue is not so clear to resolve as although we likely do prevent
the networking core from calling ieee80211_subif_start_xmit() it doesn't
mean ieee80211_xmit() internally will not be called by other parts of
mac80211 and indeed I do believe this is what is happening. I'll try
pin point the exact spot where this happens though, but I'll note though
that checking for local->suspended will *not* work since we already know
some work is being queued *and running!* and it wouldn't have if
local->suspended was true already.

static bool ieee80211_can_queue_work(struct ieee80211_local *local)
{
if (WARN(local->suspended && !local->resuming,
"queueing ieee80211 work while going to suspend\n"))
return false;

return true;
}

void ieee80211_queue_work(struct ieee80211_hw *hw, struct work_struct *work)
{
struct ieee80211_local *local = hw_to_local(hw);

if (!ieee80211_can_queue_work(local))
return;

queue_work(local->workqueue, work);
}
EXPORT_SYMBOL(ieee80211_queue_work);

The second issue can likely be fixed by fixing the first one.

Luis

2009-12-23 04:38:01

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis Rodriguez wrote:
> Did you see the last one? It turns out its the only config option
> passed by mac8021 I've seen so far so my commit log should change.

Right, that patch should work.
So the one I sent out and this one fixes the issue ?

Sujith

2009-12-22 16:55:30

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 08:20:55AM -0800, Luis Rodriguez wrote:
> On Tue, Dec 22, 2009 at 07:50:05AM -0800, Luis Rodriguez wrote:
> > On Mon, Dec 21, 2009 at 08:39:17PM -0800, Sujith Manoharan wrote:
> > > Luis Rodriguez wrote:
> > > > That log can be found here:
> > > >
> > > > http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt
> > >
> > > Thanks for the log.
> > > It's a bug in ath9k, related to PowerSave.
> > >
> > > Can you test this patch ?
> > >
> > > diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> > > index 3f5b887..419c382 100644
> > > --- a/drivers/net/wireless/ath/ath9k/main.c
> > > +++ b/drivers/net/wireless/ath/ath9k/main.c
> > > @@ -2504,6 +2504,9 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > > return; /* another wiphy still in use */
> > > }
> > >
> > > + /* Ensure HW is awake when we try to shut it down. */
> > > + ath9k_ps_wakeup(sc);
> > > +
> > > if (ah->btcoex_hw.enabled) {
> > > ath9k_hw_btcoex_disable(ah);
> > > if (ah->btcoex_hw.scheme == ATH_BTCOEX_CFG_3WIRE)
> > > @@ -2524,8 +2527,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> > > /* disable HAL and put h/w to sleep */
> > > ath9k_hw_disable(ah);
> > > ath9k_hw_configpcipowersave(ah, 1, 1);
> > > - ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > > + ath9k_ps_restore(sc);
> > >
> > > + /* Finally, put the chip in FULL SLEEP mode */
> > > + ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> > > sc->sc_flags |= SC_OP_INVALID;
> > >
> > > mutex_unlock(&sc->mutex);
> >
> >
> > Thanks for the patch, doesn't cure it though. Below is the log
> > with debug=0xa00 (CONFIG | PS), you can see some successes prior to
> > the failure.
>
> Here's the new log with 0x601, with a few pm-suspend successes above.

Let me massage this a little:

Here is one success:

> [ 249.543348] ath9k: NETWORK SLEEP -> AWAKE
> [ 249.549393] ath9k: AWAKE -> NETWORK SLEEP
> [ 249.577650] PM: Syncing filesystems ...
> [ 249.645775] ath9k: NETWORK SLEEP -> AWAKE
> [ 249.651822] ath9k: AWAKE -> NETWORK SLEEP
> [ 249.677281] done.
> [ 249.677291] PM: Preparing system for mem sleep
> [ 249.748159] ath9k: NETWORK SLEEP -> AWAKE
> [ 249.754256] ath9k: AWAKE -> NETWORK SLEEP
> [ 249.765132] ath9k: NETWORK SLEEP -> AWAKE

Device is awake prior to sending Tx BA.

> [ 249.824923] Freezing user space processes ... (elapsed 0.00 seconds) done.
> [ 249.826762] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> [ 249.826830] PM: Entering mem sleep
> [ 249.826853] Suspending console(s) (use no_console_suspend to debug)
> [ 249.832057] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> [ 249.832077] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
> [ 249.832110] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> [ 249.832130] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 6
> [ 249.832141] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 6
> [ 249.832166] ath9k: Detach Interface
> [ 249.834435] ath9k: AWAKE -> FULL-SLEEP
> [ 249.834446] ath9k: Driver halt
> [ 249.858079] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 249.858457] sd 0:0:0:0: [sda] Stopping disk
> [ 250.781437] ath9k 0000:01:00.0: PCI INT A disabled

> [ 251.087088] Back to C!

> [ 252.038696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> [ 254.521068] ath9k: Starting driver with initial channel: 2437 MHz
> [ 254.522086] ath9k: FULL-SLEEP -> AWAKE
> [ 254.533094] ath9k: ah->misc_mode 0x4
> [ 254.535214] ath9k: Attach a VIF of type: 2
> [ 254.535248] ath9k: Set channel: 2437 MHz
> [ 254.535252] ath9k: tx chmask: 1, rx chmask: 1
> [ 254.535373] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
> [ 254.541929] ath9k: ah->misc_mode 0x4
> [ 254.544052] ath9k: Set HW RX filter: 0x607
> [ 254.544058] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
> [ 254.544065] ath9k: BSS Changed PREAMBLE 1
> [ 254.544068] ath9k: BSS Changed CTS PROT 0
> [ 254.544072] ath9k: BSS Changed ASSOC 1
> [ 254.544076] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
> [ 254.546454] PM: Finishing wakeup.
> [ 254.546458] Restarting tasks ... done.
> [ 254.589051] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
> [ 254.589095] activated addBA response timer on tid 0
> [ 254.615144] Rx A-MPDU request on tid 0 result 0
> [ 254.717357] switched off addBA timer for tid 0
> [ 254.717366] Aggregation is on for tid 0
> [ 254.718297] switched off addBA timer for tid 0

Then this is the failure suspend:

> [ 270.574054] ath9k: NETWORK SLEEP -> AWAKE
> [ 270.582421] ath9k: AWAKE -> NETWORK SLEEP
> [ 270.676431] ath9k: NETWORK SLEEP -> AWAKE
> [ 270.682643] ath9k: AWAKE -> NETWORK SLEEP
> [ 270.778860] ath9k: NETWORK SLEEP -> AWAKE
> [ 270.989686] ath9k: AWAKE -> NETWORK SLEEP
> [ 271.049041] ath9k: NETWORK SLEEP -> AWAKE
> [ 271.304833] PM: Syncing filesystems ... done.
> [ 271.307636] PM: Preparing system for mem sleep
> [ 271.399307] ath9k: AWAKE -> NETWORK SLEEP

Below the device seems to go to sleep prior to sending the Tx BA, but I could have
sworn this happens in another successfull suspend before.

> [ 271.448580] Freezing user space processes ... (elapsed 0.00 seconds) done.
> [ 271.450215] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> [ 271.450296] PM: Entering mem sleep
> [ 271.450321] Suspending console(s) (use no_console_suspend to debug)
> [ 271.456054] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> [ 271.456073] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
> [ 271.456112] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> [ 271.456141] ath9k: Detach Interface
> [ 271.456161] ath9k: NETWORK SLEEP -> AWAKE
> [ 271.458525] ath9k: AWAKE -> NETWORK SLEEP
> [ 271.458533] ath9k: NETWORK SLEEP -> FULL-SLEEP
> [ 271.458544] ath9k:
> [ 271.458547] ath9k: Driver halt
> [ 271.458552] FULL-SLEEP -> AWAKE

And we leave it awake prior to suspend, hrm.

> [ 271.485081] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 271.485444] sd 0:0:0:0: [sda] Stopping disk
> [ 272.348209] ath9k 0000:01:00.0: PCI INT A disabled

> [ 272.552139] Back to C!

> [ 273.522696] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> [ 275.742070] ath9k: Starting driver with initial channel: 2437 MHz
> [ 275.891791] ath9k: timeout (100000 us) on reg 0x7000: 0xdeadbeef & 0x00000003 != 0x00000000
> [ 275.891799] ath9k: RTC stuck in MAC reset

AT this point hardware is already completely unresonsive.

> [ 275.891803] ath9k: Chip reset failed
> [ 275.891807] ath9k: Unable to reset hardware; reset status -22 (freq 2437 MHz)
> [ 275.891827] ath9k: Attach a VIF of type: 2
> [ 275.891867] ath9k: Set channel: 2437 MHz
> [ 275.891873] ath9k: tx chmask: 1, rx chmask: 1
> [ 275.891880] ath9k: Unable to set channel
> [ 275.891894] ath9k: Set HW RX filter: 0x2707
> [ 275.891901] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
> [ 275.891910] ath9k: BSS Changed PREAMBLE 1
> [ 275.891915] ath9k: BSS Changed CTS PROT 0
> [ 275.891919] ath9k: BSS Changed ASSOC 1
> [ 275.891924] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
> [ 275.894481] PM: Finishing wakeup.
> [ 275.894486] Restarting tasks ... done.
> [ 276.835592] irq 18: nobody cared (try booting with the "irqpoll" option)
> [ 276.835609] Pid: 1710, comm: Xorg Not tainted 2.6.31.4-intel-menlow #14
> [ 276.835616] Call Trace:
> [ 276.835636] [<c105ca3e>] __report_bad_irq+0x2e/0x6f
> [ 276.835646] [<c105cb74>] note_interrupt+0xf5/0x14d
> [ 276.835656] [<c105d0a4>] handle_fasteoi_irq+0x7d/0x9b
> [ 276.835668] [<c10048c1>] handle_irq+0x3b/0x46
> [ 276.835677] [<c1004103>] do_IRQ+0x41/0x95
> [ 276.835687] [<c1003189>] common_interrupt+0x29/0x30
> [ 276.835693] handlers:
> [ 276.835698] [<f89a3d03>] (ath_isr+0x0/0x12f [ath9k])
> [ 276.835739] Disabling IRQ #18

Luis

2009-12-22 15:50:08

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Mon, Dec 21, 2009 at 08:39:17PM -0800, Sujith Manoharan wrote:
> Luis Rodriguez wrote:
> > That log can be found here:
> >
> > http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt
>
> Thanks for the log.
> It's a bug in ath9k, related to PowerSave.
>
> Can you test this patch ?
>
> diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> index 3f5b887..419c382 100644
> --- a/drivers/net/wireless/ath/ath9k/main.c
> +++ b/drivers/net/wireless/ath/ath9k/main.c
> @@ -2504,6 +2504,9 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> return; /* another wiphy still in use */
> }
>
> + /* Ensure HW is awake when we try to shut it down. */
> + ath9k_ps_wakeup(sc);
> +
> if (ah->btcoex_hw.enabled) {
> ath9k_hw_btcoex_disable(ah);
> if (ah->btcoex_hw.scheme == ATH_BTCOEX_CFG_3WIRE)
> @@ -2524,8 +2527,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
> /* disable HAL and put h/w to sleep */
> ath9k_hw_disable(ah);
> ath9k_hw_configpcipowersave(ah, 1, 1);
> - ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> + ath9k_ps_restore(sc);
>
> + /* Finally, put the chip in FULL SLEEP mode */
> + ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
> sc->sc_flags |= SC_OP_INVALID;
>
> mutex_unlock(&sc->mutex);


Thanks for the patch, doesn't cure it though. Below is the log
with debug=0xa00 (CONFIG | PS), you can see some successes prior to
the failure.

[ 89.314013] PM: Syncing filesystems ... done.
[ 89.316956] PM: Preparing system for mem sleep
[ 89.476090] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 89.477287] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 89.477402] PM: Entering mem sleep
[ 89.477423] Suspending console(s) (use no_console_suspend to debug)
[ 89.481334] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 89.481350] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 89.481385] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 89.481403] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 6
[ 89.481412] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 6
[ 89.481435] ath9k: Detach Interface
[ 89.483686] ath9k: Driver halt
[ 89.506171] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 89.506558] sd 0:0:0:0: [sda] Stopping disk
[ 90.428257] ath9k 0000:01:00.0: PCI INT A disabled
[ 90.452700] ACPI handle has no context!
[ 90.452714] atl1c 0000:02:00.0: PME# disabled
[ 90.452727] atl1c 0000:02:00.0: PCI INT A disabled
[ 90.452737] ACPI handle has no context!
[ 90.496318] ata6: port disabled. ignoring.
[ 90.496393] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 90.496411] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 90.496423] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 90.496435] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 90.496445] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 90.496456] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 90.513762] i915 0000:00:02.0: PCI INT A disabled
[ 90.524494] ehci_hcd 0000:00:1d.7: PME# disabled
[ 90.535424] ACPI: Preparing to enter system sleep state S3
[ 90.623765] Disabling non-boot CPUs ...
[ 90.626106] CPU 1 is now offline
[ 90.626112] SMP alternatives: switching to UP code
[ 90.630152] CPU1 is down
[ 90.630175] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 90.630175] Back to C!
[ 90.630175] Enabling non-boot CPUs ...
[ 90.630175] SMP alternatives: switching to SMP code
[ 90.633737] Booting processor 1 APIC 0x1 ip 0x6000
[ 90.629500] Initializing CPU#1
[ 90.629500] Calibrating delay using timer specific routine.. 3331.28 BogoMIPS (lpj=1665643)
[ 90.629500] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 90.629500] CPU: L2 cache: 512K
[ 90.629500] CPU: Physical Processor ID: 0
[ 90.629500] CPU: Processor Core ID: 0
[ 90.629500] mce: CPU supports 5 MCE banks
[ 90.629500] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 90.704950] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 90.705036] Switched to high resolution mode on CPU 1
[ 90.709037] CPU1 is up
[ 90.709043] ACPI: Waking up from system sleep state S3
[ 91.068418] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x7 (was 0xf0, writing 0x200000f0)
[ 91.068437] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 91.068516] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 91.068584] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x7 (was 0xf0, writing 0x200000f0)
[ 91.068601] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 91.068668] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 91.068707] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 91.068746] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 91.068784] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 91.068832] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 91.068854] ehci_hcd 0000:00:1d.7: PME# disabled
[ 91.069022] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 91.427502] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 91.427511] i915 0000:00:02.0: setting latency timer to 64
[ 91.489057] [drm] LVDS-8: set mode 1024x600 e
[ 91.509264] pci 0000:00:02.1: PME# disabled
[ 91.509276] pci 0000:00:1b.0: PME# disabled
[ 91.509306] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 91.509317] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 91.509345] usb usb2: root hub lost power or was reset
[ 91.509371] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 91.509381] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 91.509407] usb usb3: root hub lost power or was reset
[ 91.509431] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 91.509441] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 91.509467] usb usb4: root hub lost power or was reset
[ 91.509491] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 91.509500] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 91.509527] usb usb5: root hub lost power or was reset
[ 91.509564] ehci_hcd 0000:00:1d.7: PME# disabled
[ 91.509572] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 91.509582] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 91.509616] pci 0000:00:1e.0: setting latency timer to 64
[ 91.509632] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 91.509640] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 91.511298] ata6: port disabled. ignoring.
[ 91.511330] ahci 0000:00:1f.2: setting latency timer to 64
[ 91.511406] atl1c 0000:02:00.0: PME# disabled
[ 91.511417] atl1c 0000:02:00.0: PME# disabled
[ 91.574708] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 91.574790] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 91.817141] ata3: SATA link down (SStatus 0 SControl 300)
[ 91.970144] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 91.972350] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 91.975267] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 91.975693] ata1.00: configured for UDMA/133
[ 91.986140] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0xf t4
[ 91.986149] ata1: irq_stat 0x00000040, connection status changed
[ 91.986168] ata1: hard resetting link
[ 92.047230] sd 0:0:0:0: [sda] Starting disk
[ 92.709167] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 92.798901] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 92.801624] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 92.802079] ata1.00: configured for UDMA/133
[ 92.802092] ata1: EH complete
[ 92.960162] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 93.241146] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 93.956141] ath9k: Starting driver with initial channel: 2437 MHz
[ 93.970209] ath9k: Attach a VIF of type: 2
[ 93.970243] ath9k: Set channel: 2437 MHz
[ 93.970248] ath9k: tx chmask: 1, rx chmask: 1
[ 93.970372] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 93.979039] ath9k: Set HW RX filter: 0x607
[ 93.979046] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 93.979052] ath9k: BSS Changed PREAMBLE 1
[ 93.979056] ath9k: BSS Changed CTS PROT 0
[ 93.979060] ath9k: BSS Changed ASSOC 1
[ 93.979063] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 93.981491] PM: Finishing wakeup.
[ 93.981496] Restarting tasks ... done.
[ 93.989532] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 93.989575] activated addBA response timer on tid 0
[ 93.991477] Rx A-MPDU request on tid 0 result 0
[ 93.992306] switched off addBA timer for tid 0
[ 93.992314] Aggregation is on for tid 0
[ 94.194880] ath9k: Reconfigure Beacon timers based on timestamp from the AP
[ 104.540982] PM: Syncing filesystems ... done.
[ 104.767013] PM: Preparing system for mem sleep
[ 104.913718] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 104.915436] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 104.915545] PM: Entering mem sleep
[ 104.915568] Suspending console(s) (use no_console_suspend to debug)
[ 104.920338] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 104.920354] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 104.920390] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 104.920477] ath9k: Detach Interface
[ 104.922778] ath9k: Driver halt
[ 104.946162] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 104.946594] sd 0:0:0:0: [sda] Stopping disk
[ 105.863851] ath9k 0000:01:00.0: PCI INT A disabled
[ 105.887700] ACPI handle has no context!
[ 105.887714] atl1c 0000:02:00.0: PME# disabled
[ 105.887724] ACPI handle has no context!
[ 105.931316] ata6: port disabled. ignoring.
[ 105.931391] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 105.931409] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 105.931422] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 105.931433] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 105.931444] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 105.931454] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 105.947618] i915 0000:00:02.0: PCI INT A disabled
[ 105.958499] ehci_hcd 0000:00:1d.7: PME# disabled
[ 105.969427] ACPI: Preparing to enter system sleep state S3
[ 106.057766] Disabling non-boot CPUs ...
[ 106.060109] CPU 1 is now offline
[ 106.060114] SMP alternatives: switching to UP code
[ 106.064092] CPU1 is down
[ 106.064115] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 106.064115] Back to C!
[ 106.064115] Enabling non-boot CPUs ...
[ 106.064115] SMP alternatives: switching to SMP code
[ 106.067695] Booting processor 1 APIC 0x1 ip 0x6000
[ 106.063466] Initializing CPU#1
[ 106.063466] Calibrating delay using timer specific routine.. 3331.28 BogoMIPS (lpj=1665640)
[ 106.063466] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 106.063466] CPU: L2 cache: 512K
[ 106.063466] CPU: Physical Processor ID: 0
[ 106.063466] CPU: Processor Core ID: 0
[ 106.063466] mce: CPU supports 5 MCE banks
[ 106.063466] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 106.138940] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 106.139028] Switched to high resolution mode on CPU 1
[ 106.143036] CPU1 is up
[ 106.143042] ACPI: Waking up from system sleep state S3
[ 106.503519] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 106.503607] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 106.503691] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 106.503765] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 106.503809] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 106.503852] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 106.503895] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 106.503948] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 106.503973] ehci_hcd 0000:00:1d.7: PME# disabled
[ 106.504158] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 106.866491] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 106.866500] i915 0000:00:02.0: setting latency timer to 64
[ 106.928044] [drm] LVDS-8: set mode 1024x600 e
[ 106.948245] pci 0000:00:02.1: PME# disabled
[ 106.948259] pci 0000:00:1b.0: PME# disabled
[ 106.948291] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 106.948303] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 106.948331] usb usb2: root hub lost power or was reset
[ 106.948358] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 106.948367] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 106.948394] usb usb3: root hub lost power or was reset
[ 106.948418] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 106.948428] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 106.948454] usb usb4: root hub lost power or was reset
[ 106.948478] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 106.948487] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 106.948514] usb usb5: root hub lost power or was reset
[ 106.948552] ehci_hcd 0000:00:1d.7: PME# disabled
[ 106.948561] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 106.948570] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 106.948604] pci 0000:00:1e.0: setting latency timer to 64
[ 106.948620] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 106.948628] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 106.950291] ata6: port disabled. ignoring.
[ 106.950322] ahci 0000:00:1f.2: setting latency timer to 64
[ 106.950400] atl1c 0000:02:00.0: PME# disabled
[ 106.950410] atl1c 0000:02:00.0: PME# disabled
[ 107.013705] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 107.013790] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 107.256171] ata3: SATA link down (SStatus 0 SControl 300)
[ 107.307148] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 107.309315] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 107.312183] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 107.312628] ata1.00: configured for UDMA/133
[ 107.323167] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0xf t4
[ 107.323176] ata1: irq_stat 0x00000040, connection status changed
[ 107.323195] ata1: hard resetting link
[ 107.485042] sd 0:0:0:0: [sda] Starting disk
[ 108.046178] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 108.118587] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 108.121397] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 108.121810] ata1.00: configured for UDMA/133
[ 108.121822] ata1: EH complete
[ 108.280150] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 108.560140] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 109.275204] ath9k: Starting driver with initial channel: 2437 MHz
[ 109.289246] ath9k: Attach a VIF of type: 2
[ 109.289299] ath9k: Set channel: 2437 MHz
[ 109.289305] ath9k: tx chmask: 1, rx chmask: 1
[ 109.289406] ath9k: (2437 MHz) -> (2437 MHz), chanwidth: 1
[ 109.298089] ath9k: Set HW RX filter: 0x607
[ 109.298096] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 109.298102] ath9k: BSS Changed PREAMBLE 1
[ 109.298106] ath9k: BSS Changed CTS PROT 0
[ 109.298109] ath9k: BSS Changed ASSOC 1
[ 109.298113] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 109.300513] PM: Finishing wakeup.
[ 109.300518] Restarting tasks ... done.
[ 109.330297] Open BA session requested for 00:22:6b:56:fd:e8 tid 0
[ 109.330341] activated addBA response timer on tid 0
[ 109.335364] Rx A-MPDU request on tid 0 result 0
[ 109.336199] switched off addBA timer for tid 0
[ 109.336207] Aggregation is on for tid 0
[ 109.532250] ath9k: Reconfigure Beacon timers based on timestamp from the AP
[ 115.600983] PM: Syncing filesystems ... done.
[ 115.603769] PM: Preparing system for mem sleep
[ 115.747184] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 115.748611] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
[ 115.748728] PM: Entering mem sleep
[ 115.748750] Suspending console(s) (use no_console_suspend to debug)
[ 115.754153] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 115.754174] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
[ 115.754216] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
[ 115.754245] ath9k: Detach Interface
[ 115.756642] ath9k: Driver halt
[ 115.783163] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 115.783598] sd 0:0:0:0: [sda] Stopping disk
[ 116.710137] ath9k 0000:01:00.0: PCI INT A disabled
[ 116.734702] ACPI handle has no context!
[ 116.734716] atl1c 0000:02:00.0: PME# disabled
[ 116.734726] ACPI handle has no context!
[ 116.778319] ata6: port disabled. ignoring.
[ 116.778395] ata_piix 0000:00:1f.1: PCI INT A disabled
[ 116.778413] ehci_hcd 0000:00:1d.7: PCI INT A disabled
[ 116.778425] uhci_hcd 0000:00:1d.3: PCI INT D disabled
[ 116.778436] uhci_hcd 0000:00:1d.2: PCI INT C disabled
[ 116.778447] uhci_hcd 0000:00:1d.1: PCI INT B disabled
[ 116.778458] uhci_hcd 0000:00:1d.0: PCI INT A disabled
[ 116.794206] i915 0000:00:02.0: PCI INT A disabled
[ 116.805495] ehci_hcd 0000:00:1d.7: PME# disabled
[ 116.816424] ACPI: Preparing to enter system sleep state S3
[ 116.910764] Disabling non-boot CPUs ...
[ 116.913107] CPU 1 is now offline
[ 116.913113] SMP alternatives: switching to UP code
[ 116.917119] CPU1 is down
[ 116.917142] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
[ 116.917142] Back to C!
[ 116.917142] Enabling non-boot CPUs ...
[ 116.917142] SMP alternatives: switching to SMP code
[ 116.920718] Booting processor 1 APIC 0x1 ip 0x6000
[ 116.916492] Initializing CPU#1
[ 116.916492] Calibrating delay using timer specific routine.. 3331.29 BogoMIPS (lpj=1665646)
[ 116.916492] CPU: L1 I cache: 32K, L1 D cache: 24K
[ 116.916492] CPU: L2 cache: 512K
[ 116.916492] CPU: Physical Processor ID: 0
[ 116.916492] CPU: Processor Core ID: 0
[ 116.916492] mce: CPU supports 5 MCE banks
[ 116.916492] x86 PAT enabled: cpu 1, old 0x7040600070406, new 0x7010600070106
[ 116.991936] CPU1: Intel(R) Atom(TM) CPU N280 @ 1.66GHz stepping 02
[ 116.992269] Switched to high resolution mode on CPU 1
[ 116.996025] CPU1 is up
[ 116.996032] ACPI: Waking up from system sleep state S3
[ 117.358521] pcieport-driver 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100104, writing 0x100504)
[ 117.358609] pcieport-driver 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100107, writing 0x100507)
[ 117.358694] pcieport-driver 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100106, writing 0x100506)
[ 117.358767] uhci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 117.358812] uhci_hcd 0000:00:1d.1: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 117.358855] uhci_hcd 0000:00:1d.2: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 117.358898] uhci_hcd 0000:00:1d.3: restoring config space at offset 0x1 (was 0x2800005, writing 0x2800001)
[ 117.358951] ehci_hcd 0000:00:1d.7: restoring config space at offset 0x1 (was 0x2900106, writing 0x2900102)
[ 117.358976] ehci_hcd 0000:00:1d.7: PME# disabled
[ 117.359162] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[ 117.721142] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 117.721150] i915 0000:00:02.0: setting latency timer to 64
[ 117.782697] [drm] LVDS-8: set mode 1024x600 e
[ 117.802897] pci 0000:00:02.1: PME# disabled
[ 117.802907] pci 0000:00:1b.0: PME# disabled
[ 117.802934] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 117.802944] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 117.802973] usb usb2: root hub lost power or was reset
[ 117.802998] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 22 (level, low) -> IRQ 22
[ 117.803021] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 117.803048] usb usb3: root hub lost power or was reset
[ 117.803073] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 21 (level, low) -> IRQ 21
[ 117.803083] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[ 117.803109] usb usb4: root hub lost power or was reset
[ 117.803133] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 20 (level, low) -> IRQ 20
[ 117.803143] uhci_hcd 0000:00:1d.3: setting latency timer to 64
[ 117.803169] usb usb5: root hub lost power or was reset
[ 117.803207] ehci_hcd 0000:00:1d.7: PME# disabled
[ 117.803215] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 117.803224] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[ 117.803264] pci 0000:00:1e.0: setting latency timer to 64
[ 117.803285] ata_piix 0000:00:1f.1: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 117.803296] ata_piix 0000:00:1f.1: setting latency timer to 64
[ 117.804929] ata6: port disabled. ignoring.
[ 117.804956] ahci 0000:00:1f.2: setting latency timer to 64
[ 117.805035] atl1c 0000:02:00.0: PME# disabled
[ 117.805043] atl1c 0000:02:00.0: PME# disabled
[ 117.868714] atl1c 0000:02:00.0: irq 28 for MSI/MSI-X
[ 117.868799] ath9k 0000:01:00.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
[ 118.110161] ata3: SATA link down (SStatus 0 SControl 300)
[ 118.161152] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 118.165385] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 118.168239] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 118.168643] ata1.00: configured for UDMA/133
[ 118.179174] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0xf t4
[ 118.179183] ata1: irq_stat 0x00400040, connection status changed
[ 118.179202] ata1: hard resetting link
[ 118.340197] sd 0:0:0:0: [sda] Starting disk
[ 118.902173] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 118.971400] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 118.974183] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 118.974608] ata1.00: configured for UDMA/133
[ 118.974621] ata1: EH complete
[ 119.133147] usb 1-8: reset high speed USB device using ehci_hcd and address 3
[ 119.413139] usb 5-1: reset full speed USB device using uhci_hcd and address 2
[ 120.128210] ath9k: Starting driver with initial channel: 2437 MHz
[ 120.277768] ath9k: timeout (100000 us) on reg 0x7000: 0xdeadbeef & 0x00000003 != 0x00000000
[ 120.277804] ath9k: Attach a VIF of type: 2
[ 120.277853] ath9k: Set channel: 2437 MHz
[ 120.277860] ath9k: tx chmask: 1, rx chmask: 1
[ 120.277875] ath9k: Set HW RX filter: 0x2707
[ 120.277883] ath9k: RX filter 0x0 bssid 00:22:6b:56:fd:e8 aid 0x0
[ 120.277892] ath9k: BSS Changed PREAMBLE 1
[ 120.277897] ath9k: BSS Changed CTS PROT 0
[ 120.277902] ath9k: BSS Changed ASSOC 1
[ 120.277906] ath9k: Bss Info ASSOC 1, bssid: 00:22:6b:56:fd:e8
[ 120.280886] PM: Finishing wakeup.
[ 120.280892] Restarting tasks ... done.
[ 121.233472] irq 18: nobody cared (try booting with the "irqpoll" option)
[ 121.233488] Pid: 2336, comm: gnome-terminal Not tainted 2.6.31.4-intel-menlow #13
[ 121.233495] Call Trace:
[ 121.233513] [<c105ca3e>] __report_bad_irq+0x2e/0x6f
[ 121.233525] [<c105cb74>] note_interrupt+0xf5/0x14d
[ 121.233535] [<c105d0a4>] handle_fasteoi_irq+0x7d/0x9b
[ 121.233546] [<c10048c1>] handle_irq+0x3b/0x46
[ 121.233555] [<c1004103>] do_IRQ+0x41/0x95
[ 121.233564] [<c1003189>] common_interrupt+0x29/0x30
[ 121.233571] handlers:
[ 121.233576] [<f89bad03>] (ath_isr+0x0/0x12f [ath9k])
[ 121.233616] Disabling IRQ #18
[ 134.922394] atl1c 0000:02:00.0: atl1c: eth0 NIC Link is Up<100 Mbps Full Duplex>

2009-12-23 01:16:46

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

OK I have to go now but I managed to get this working without the
issue coming up. At this point I am not sure if all of these are
required but I cherry picked 2 patches from wireless-testing and then
added 4, one based on sujith's suggestion.

http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0001-mac80211-fix-resume.patch
http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0002-mac80211-fix-WMM-AP-settings-application.patch

http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0003-ath9k-set-and-restore-ps-prior-to-stop-and-interface.patch
http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0004-ath9k-ensure-hardware-is-awake-during-ampdu-TX-actio.patch

http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0005-ath9k-synch-TX-DMA-buffer-upon-TX-cancelation.patch
http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0006-ath9k-do-not-wake-up-device-if-it-hasn-t-been-starte.patch

Its likely only patch 3, 4, and 6 are the only ones required. In fact
maybe even 6 will fix it, but I just gotta go so cannot test that. I
was able to resume about 10 times consecutively which I was unable to
do before.

Luis

2009-12-23 02:03:07

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

(Trimming CC List)

Luis Rodriguez wrote:
> > Here's the new log with 0x601, with a few pm-suspend successes above.

The only issue here is a call to wakeup the chip comes
after the ->stop() callback. And that happens here:

> > [ 271.448580] Freezing user space processes ... (elapsed 0.00 seconds) done.
> > [ 271.450215] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
> > [ 271.450296] PM: Entering mem sleep
> > [ 271.450321] Suspending console(s) (use no_console_suspend to debug)
> > [ 271.456054] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456073] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456112] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
> > [ 271.456141] ath9k: Detach Interface
> > [ 271.456161] ath9k: NETWORK SLEEP -> AWAKE
> > [ 271.458525] ath9k: AWAKE -> NETWORK SLEEP
> > [ 271.458533] ath9k: NETWORK SLEEP -> FULL-SLEEP
> > [ 271.458544] ath9k:
> > [ 271.458547] ath9k: Driver halt
> > [ 271.458552] FULL-SLEEP -> AWAKE

The actual issue then lies in the callsite, probably mac80211 - having stopped
the driver (during suspend), any notifications/calls to the driver are invalid.

But strange that I am not able to reproduce this.
What distribution are you using ? Also, the version of NM ?

Sujith

2009-12-22 19:12:56

by Luis R. Rodriguez

Subject: Re: lspci CorrErr- UnsuppReq- changes (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

Changing the subject to the PCI specific questions. Hoping someone
from linux-pci can help me understand the meaning of the PCI config
space changes a little better.

I notice that when my device becomes unresponsive after pm-suspend both
CorrErr+ UnsuppReq+ change to
CorrErr- UnsuppReq- .

These should be:

#define PCI_EXP_DEVSTA 10 /* Device Status */
#define PCI_EXP_DEVSTA_CED 0x01 /* Correctable Error Detected */
#define PCI_EXP_DEVSTA_NFED 0x02 /* Non-Fatal Error Detected */
#define PCI_EXP_DEVSTA_FED 0x04 /* Fatal Error Detected */
#define PCI_EXP_DEVSTA_URD 0x08 /* Unsupported Request Detected */
#define PCI_EXP_DEVSTA_AUXPD 0x10 /* AUX Power Detected */
#define PCI_EXP_DEVSTA_TRPND 0x20 /* Transactions Pending */

I don't see the kernel using them except for in tg3 tg3_chip_reset() to
clear the PCI_EXP_DEVSTA on PCI-express upon reset for some reason:

http://lxr.linux.no/#linux+v2.6.32/drivers/net/tg3.c#L6522

But this was added as a work around:

commit 5e7dfd0fb94abed04f59481d1ce0cc06a892048a
Author: Matt Carlson <[email protected]>
Date: Fri Nov 21 17:18:16 2008 -0800

tg3: Prevent corruption at 10 / 100Mbps w CLKREQ

This patch disables CLKREQ at 10Mbps and 100Mbps to workaround a TX BD
corruption issue. This problem only affects the 5784 and 5761 (and
57780 AX) ASIC revisions.

Signed-off-by: Matt Carlson <[email protected]>
Signed-off-by: Michael Chan <[email protected]>
Signed-off-by: David S. Miller <[email protected]>

Apart from this I don't see any other uses for PCI_EXP_DEVSTA_CED and
PCI_EXP_DEVSTA_URD on the kernel as of 2.6.32 so I will likely need
to start looking at the PCI spec to decipher this. But before I do so
I still am curious what the lspci difference in output for these two
on from + to - would mean for these two.

I leave below the relevant PCI sections of my last post.

Luis

On Mon, Dec 21, 2009 at 09:23:55PM -0500, Luis R. Rodriguez wrote:
> As for the specific Asus eeepc 1008HA issue what I'm seeing is ath9k
> talking to harware fine prior to suspend, disabling harware and then
> upon resume it becomes unusable, failing at the first harware reset.
> lspci tells me the following when the device is functional, both during
> initial boot, and during successfull pm-suspend cycles:
>
> 01:00.0 Network controller: Atheros Communications Inc. AR9285 Wireless Network Adapter (PCI-Express) (rev 01)
> Subsystem: Device 1a3b:1089
> Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
> Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
> Latency: 0, Cache Line Size: 32 bytes
> Interrupt: pin A routed to IRQ 18
> Region 0: Memory at fbef0000 (64-bit, non-prefetchable) [size=64K]
> Capabilities: [40] Power Management version 3
> Flags: PMEClk- DSI- D1+ D2- AuxCurrent=375mA PME(D0+,D1+,D2-,D3hot+,D3cold+)
> Status: D0 PME-Enable- DSel=0 DScale=0 PME-
> Capabilities: [50] Message Signalled Interrupts: Mask- 64bit- Queue=0/0 Enable-
> Address: 00000000 Data: 0000
> Capabilities: [60] Express (v2) Legacy Endpoint, MSI 00
> DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 <64us
> ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
> DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
> RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop-
> MaxPayload 128 bytes, MaxReadReq 512 bytes
> DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
> LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
> ClockPM- Suprise- LLActRep- BwNot-
> LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
> ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
> LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
> Capabilities: [100] Advanced Error Reporting <?>
> Capabilities: [140] Virtual Channel <?>
> Capabilities: [160] Device Serial Number 12-14-24-ff-ff-17-15-00
> Capabilities: [170] Power Budgeting <?>
> Kernel driver in use: ath9k
> Kernel modules: ath9k
>
> I do notice a difference when resume goes bust and the ath9k device becomes unhappy. This
> is what I see:
>
> --- lspci-ok.txt 2009-12-21 17:22:24.000000000 -0800
> +++ lspci-busted.txt 2009-12-21 17:22:50.000000000 -0800
> @@ -16,7 +16,7 @@
> DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
> RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop-
> MaxPayload 128 bytes, MaxReadReq 512 bytes
> - DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
> + DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
> LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
> ClockPM- Suprise- LLActRep- BwNot-
> LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
>
> The line in question is the PCI device status. The CorrErr indicates
> "Correctable Error Detected" and the UnsuppReq indicates "Unsupported
> Request Detected". Its not entirely clear to me what exact unsupported
> request must have been sent. I've considered getting help to look at this
> with a PCI analyzer but first I wanted to check and see if others are seeing
> this with the 1008HA or similar platform familes and if there are pointers
> some can give.

2009-12-23 02:39:22

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 6:19 PM, Sujith <[email protected]> wrote:
> (Trimming CC List)
>
> Luis Rodriguez wrote:
>> > Here's the new log with 0x601, with a few pm-suspend successes above.
>
> The only issue here is a call to wakeup the chip comes
> after the ->stop() callback. And that happens here:
>
>> > [  271.448580] Freezing user space processes ... (elapsed 0.00 seconds) done.
>> > [  271.450215] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
>> > [  271.450296] PM: Entering mem sleep
>> > [  271.450321] Suspending console(s) (use no_console_suspend to debug)
>> > [  271.456054] Tx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
>> > [  271.456073] Stopping Tx BA session for 00:22:6b:56:fd:e8 tid 0
>> > [  271.456112] Rx BA session stop requested for 00:22:6b:56:fd:e8 tid 0
>> > [  271.456141] ath9k: Detach Interface
>> > [  271.456161] ath9k: NETWORK SLEEP -> AWAKE
>> > [  271.458525] ath9k: AWAKE -> NETWORK SLEEP
>> > [  271.458533] ath9k: NETWORK SLEEP -> FULL-SLEEP
>> > [  271.458544] ath9k:
>> > [  271.458547] ath9k: Driver halt
>> > [  271.458552] FULL-SLEEP -> AWAKE
>
> The actual issue then lies in the callsite, probably mac80211 - having stopped
> the driver (during suspend), any notifications/calls to the driver are invalid.
>
> But strange that I am not able to reproduce this.

I wasn't able to reproduce at home, only at work in a busy
environment, but can't say I tested that much at home.

> What distribution are you using ? Also, the version of NM ?

I'm on Ubuntu 9.10, I'm not using NM though, I'm running
wpa_supplicant manually. To reproduce I had to force wpa_supplicant to
remain connected. wpa_supplicant does this if not interrupted. NM will
instead deauth and disassoc you prior to suspend.

Have you tried using wpa_supplicant alone?

Luis

2009-12-22 04:22:59

by Sujith

Subject: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis Rodriguez wrote:
> That log can be found here:
>
> http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt

Thanks for the log.
It's a bug in ath9k, related to PowerSave.

Can you test this patch ?

diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
index 3f5b887..419c382 100644
--- a/drivers/net/wireless/ath/ath9k/main.c
+++ b/drivers/net/wireless/ath/ath9k/main.c
@@ -2504,6 +2504,9 @@ static void ath9k_stop(struct ieee80211_hw *hw)
return; /* another wiphy still in use */
}

+ /* Ensure HW is awake when we try to shut it down. */
+ ath9k_ps_wakeup(sc);
+
if (ah->btcoex_hw.enabled) {
ath9k_hw_btcoex_disable(ah);
if (ah->btcoex_hw.scheme == ATH_BTCOEX_CFG_3WIRE)
@@ -2524,8 +2527,10 @@ static void ath9k_stop(struct ieee80211_hw *hw)
/* disable HAL and put h/w to sleep */
ath9k_hw_disable(ah);
ath9k_hw_configpcipowersave(ah, 1, 1);
- ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
+ ath9k_ps_restore(sc);

+ /* Finally, put the chip in FULL SLEEP mode */
+ ath9k_setpower(sc, ATH9K_PM_FULL_SLEEP);
sc->sc_flags |= SC_OP_INVALID;

mutex_unlock(&sc->mutex);

2009-12-23 04:01:05

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 8:06 PM, Sujith <[email protected]> wrote:
> Luis Rodriguez wrote:
>> > diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
>> > index 419c382..7fdcc6b 100644
>> > --- a/drivers/net/wireless/ath/ath9k/main.c
>> > +++ b/drivers/net/wireless/ath/ath9k/main.c
>> > @@ -2673,6 +2673,11 @@ static int ath9k_config(struct ieee80211_hw *hw, u32 changed)
>> >
>> >        mutex_lock(&sc->mutex);
>> >
>> > +       if (sc->sc_flags & SC_OP_INVALID) {
>> > +               mutex_unlock(&sc->mutex);
>> > +               return 0;
>> > +       }
>> > +
>> >        /*
>> >         * Leave this as the first check because we need to turn on the
>> >         * radio if it was disabled before prior to processing the rest
>>
>> That ones busts the resume.
>
> Weird, checking for the device status before allowing configuration
> changes is valid. Not sure why this is happening.

The proper and more clean solution is to see where in mac80211 this
gets called and avoid the call when local->suspended if
local->suspended is true after driver->stop() I forget.

Luis

2009-12-23 03:31:27

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis R. Rodriguez wrote:
> On Tue, Dec 22, 2009 at 6:29 PM, Sujith <[email protected]> wrote:
> > Luis Rodriguez wrote:
> >> I just tried adding the PM stuff over ath9k_remove_interface and I still get the
> >> issue. The patch is below.
> >
> > The HW is not accessed in ->remove_interface(), so this patch is not necessary.
>
> How about when remove_interface calls ath9k_hw_stoptxdma() ?

Yep, that is correct - but it should not affect here since we are in managed
mode.

2009-12-23 19:11:32

by Johannes Berg

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, 2009-12-23 at 11:08 -0800, Luis R. Rodriguez wrote:

> So you want drivers to handle start() failures (even if its not for
> resume) with an unregistration to mac80211?

Not necessarily. If it's a temporary error, that's fine, of course, but
if the hardware is suddenly inaccessible for whatever reason then yes,
of course, unregistering is the only good choice no matter when it
happens.

johannes

Attachments:

2009-12-23 19:19:55

by Luis R. Rodriguez

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, Dec 23, 2009 at 11:11 AM, Johannes Berg
<[email protected]> wrote:
> On Wed, 2009-12-23 at 11:08 -0800, Luis R. Rodriguez wrote:
>
>> So you want drivers to handle start() failures (even if its not for
>> resume) with an unregistration to mac80211?
>
> Not necessarily. If it's a temporary error, that's fine, of course, but
> if the hardware is suddenly inaccessible for whatever reason then yes,
> of course, unregistering is the only good choice no matter when it
> happens.

Reason for me suggesting for mac80211 to deal with this is drivers
won't know if their failed start() call will have been from resume and
we likely won't add a bool to start() callback since we already
debated this a while back.

I don't really care about hardware failures in other cases right now,
and do think resume is reasonable enough to check for and handle on
mac8021 alone. Since stop() would have stopped everything in the
driver and is documented as such I don't see why it would be
complicated to unregister it instead from mac80211.

Luis

2009-12-24 12:43:50

by Johannes Berg

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, 2009-12-23 at 11:19 -0800, Luis R. Rodriguez wrote:

> Reason for me suggesting for mac80211 to deal with this is drivers
> won't know if their failed start() call will have been from resume and
> we likely won't add a bool to start() callback since we already
> debated this a while back.
>
> I don't really care about hardware failures in other cases right now,

Which is the problem.

If your hardware suddenly fails, _regardless_ of when, you need to
unregister from mac80211 since otherwise you'll get loads of callbacks
to failed hardware.

Resume really isn't as special as you'd like to believe.

johannes

Attachments:

2009-12-23 19:08:41

by Luis R. Rodriguez

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, Dec 23, 2009 at 08:47:08AM -0800, Johannes Berg wrote:
> On Wed, 2009-12-23 at 08:28 -0800, Luis R. Rodriguez wrote:
>
> > > Well it seems to me that if the driver determines that the hardware
> > is
> > > unreachable or not responding, it would unregister it from mac80211,
> > > which would clean up all user-visible state, obviously.
> >
> > The drivers would not know this until it fails on the first call
> > from mac80211 which would be start().
>
> Which is why this patch may be a good way to solve that particular
> problem.

Sure but as you and I noted this is not the only thing required.

> > > The patch above seems ok to me, but basically papers over the
> > problem.
> > > If the start there fails, the driver will have to unregister the hw
> > > since any subsequent start will fail as well.
> >
> > How about just having mac80211 do that for drivers where the start()
> > fails and we are resuming? I can give that a shot.
>
> No way, the driver will invariably assume things are still going and
> might later unregister etc. Too much magic.

So you want drivers to handle start() failures (even if its not for resume)
with an unregistration to mac80211?

Luis

2009-12-23 16:25:49

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 07:47:46PM -0800, Sujith Manoharan wrote:
> Luis R. Rodriguez wrote:
> > On Tue, Dec 22, 2009 at 6:29 PM, Sujith <[email protected]> wrote:
> > > Luis Rodriguez wrote:
> > >> I just tried adding the PM stuff over ath9k_remove_interface and I still get the
> > >> issue. The patch is below.
> > >
> > > The HW is not accessed in ->remove_interface(), so this patch is not necessary.
> >
> > How about when remove_interface calls ath9k_hw_stoptxdma() ?
>
> Yep, that is correct - but it should not affect here since we are in managed
> mode.

Yeah good point, but its still correct to add that then.

Luis

2009-12-23 16:28:15

by Luis R. Rodriguez

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, Dec 23, 2009 at 04:08:01AM -0800, Johannes Berg wrote:
> On Tue, 2009-12-22 at 14:30 -0500, Luis R. Rodriguez wrote:
>
> > Johannes, any preferences how to handle this? The patch below avoids
> > the Interrupt being turned off but its not enough given that we still
> > could be associated according to userspace. If the hardware is
> > unresponsive maybe it is best to just let the IRQ go disabled, not
> > sure, but its likely not what happens in all cases.
> >
> > Trimming out the irrelevant parts below.
>
> > http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless
> > /irq-disabled.txt
> > >
> > > This can be fixed by something like the following:
> > >
> > > diff --git a/net/mac80211/util.c b/net/mac80211/util.c
> > > index e6c08da..63d42fa 100644
> > > --- a/net/mac80211/util.c
> > > +++ b/net/mac80211/util.c
> > > @@ -1031,7 +1031,14 @@ int ieee80211_reconfig(struct ieee80211_local
> > *local)
> > >
> > > /* restart hardware */
> > > if (local->open_count) {
> > > + /*
> > > + * Upon resume hardware can sometimes be goofy due to
> > > + * various platform issues, so restarting the device may
> > > + * at times not work immediately. Propagate the error.
> > > + */
> > > res = drv_start(local);
> > > + if (res)
> > > + return res;
> > >
> > > ieee80211_led_radio(local, true);
> > > }
> > >
> > > But this isn't enough. And since we cannot exactly talk to hardware
> > > we can't try to send a deassoc as harware would be unresponsive. I
> > > also don't see us handling such cases before either on cfg80211 or
> > > mac80211, so curious what we should do.
>
> Well it seems to me that if the driver determines that the hardware is
> unreachable or not responding, it would unregister it from mac80211,
> which would clean up all user-visible state, obviously.

The drivers would not know this until it fails on the first call
from mac80211 which would be start().

> The patch above seems ok to me, but basically papers over the problem.
> If the start there fails, the driver will have to unregister the hw
> since any subsequent start will fail as well.

How about just having mac80211 do that for drivers where the start()
fails and we are resuming? I can give that a shot.

> The way I see it, it's like a USB unplug while suspended/hibernated ...
> the driver notices that and remo

I see, in this case though I'd prefer if mac80211 could do more of
the work instead of requiring each driver to treat start() failures
by unregistering themselves, specially since we don't inform drivers
they are coming back from resume on start().

Luis

2009-12-23 19:01:57

by Johannes Berg

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Wed, 2009-12-23 at 08:28 -0800, Luis R. Rodriguez wrote:

> > Well it seems to me that if the driver determines that the hardware
> is
> > unreachable or not responding, it would unregister it from mac80211,
> > which would clean up all user-visible state, obviously.
>
> The drivers would not know this until it fails on the first call
> from mac80211 which would be start().

Which is why this patch may be a good way to solve that particular
problem.

> > The patch above seems ok to me, but basically papers over the
> problem.
> > If the start there fails, the driver will have to unregister the hw
> > since any subsequent start will fail as well.
>
> How about just having mac80211 do that for drivers where the start()
> fails and we are resuming? I can give that a shot.

No way, the driver will invariably assume things are still going and
might later unregister etc. Too much magic.

johannes

Attachments:

2009-12-23 02:12:50

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis Rodriguez wrote:
> I just tried adding the PM stuff over ath9k_remove_interface and I still get the
> issue. The patch is below.

The HW is not accessed in ->remove_interface(), so this patch is not necessary.

Sujith

2009-12-22 19:30:13

by Luis R. Rodriguez

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

Starting a 3rd thread based on my original post to focus on the
corner case of the driver start() op failing.

Johannes, any preferences how to handle this? The patch below avoids
the Interrupt being turned off but its not enough given that we still
could be associated according to userspace. If the hardware is
unresponsive maybe it is best to just let the IRQ go disabled, not
sure, but its likely not what happens in all cases.

Trimming out the irrelevant parts below.

On Mon, Dec 21, 2009 at 09:23:55PM -0500, Luis R. Rodriguez wrote:
> I'm testing ath9k on an Asus eeepc 1008HA on a 2.6.32.2 kernel
> and ran into a suspend corner case issue which we do not handle
> yet. From what I've debugged so far it appears to me ath9k is
> doing everything it should to suspend. mac80211 drivers don't
> really do much on suspend except listen to mac80211. In the
> suspend case the mac80211 first stops TX, flushes out all packets,
> tears down aggregation, removes peers (if STA this would be your
> AP), removes all interfaces and finally call the mac80211 driver
> stop() callback for the driver. The driver is expected to have
> completed the stop() successfully, it shall not fail. It should
> be noted we never disassociate from the AP, this is left to
> userspace to figure out if it wants to do this prior to suspend.
> Network manger does this, for example. If you run the supplicant
> manually though and if your AP does not kick you off you could
> end up suspending and resumeing and still have a valid auth/assoc
> to the AP.
>
> Upon resume mac80211 first calls the mac80211 start() driver callback,
> then re-add the interfaces, then the peers (your AP), etc. The corner
> case I just ran into was that the mac80211 driver start() callback
> *can* fail if your bus is screwy. You would likely see other sorts
> of errors when this sort of thing happens but I'm not and when we
> try to start() on ath9k we fail as the harware is completely
> unresponsive. What ends up happening then currently is the driver
> will enable interrupts and obviously though since we cannot even
> reset the hardware these interrupts will have gone unhandled and
> the interrupt gets disabled by the kernel. I reproduced this on
> vanilla 2.6.32.2 but I only did get full ath9k debug logs when
> testing against 2.6.31 with 2.6.32.2 wireless bits. That log can
> be found here:
>
> http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless/irq-disabled.txt
>
> This can be fixed by something like the following:
>
> diff --git a/net/mac80211/util.c b/net/mac80211/util.c
> index e6c08da..63d42fa 100644
> --- a/net/mac80211/util.c
> +++ b/net/mac80211/util.c
> @@ -1031,7 +1031,14 @@ int ieee80211_reconfig(struct ieee80211_local *local)
>
> /* restart hardware */
> if (local->open_count) {
> + /*
> + * Upon resume hardware can sometimes be goofy due to
> + * various platform issues, so restarting the device may
> + * at times not work immediately. Propagate the error.
> + */
> res = drv_start(local);
> + if (res)
> + return res;
>
> ieee80211_led_radio(local, true);
> }
>
> But this isn't enough. And since we cannot exactly talk to hardware
> we can't try to send a deassoc as harware would be unresponsive. I
> also don't see us handling such cases before either on cfg80211 or
> mac80211, so curious what we should do. Doing the above is not enough
> since userspace will still believe it will be associated if it left
> the device in an associated state. If you end up killing userspace
> and restarting you'll end up with crawling into cfg80211/mac80211
> warnings due to the unexpected state we left things in. This is
> currently busted on 2.6.32.2 and I don't see an obvious fix, hoping
> others might.

2009-12-23 02:40:54

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 6:29 PM, Sujith <[email protected]> wrote:
> Luis Rodriguez wrote:
>> I just tried adding the PM stuff over ath9k_remove_interface and I still get the
>> issue. The patch is below.
>
> The HW is not accessed in ->remove_interface(), so this patch is not necessary.

How about when remove_interface calls ath9k_hw_stoptxdma() ?

Luis

2009-12-23 19:07:07

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Wed, Dec 23, 2009 at 10:33:51AM -0800, Luis Rodriguez wrote:
> The issues are as follows:
>
> 1) We stop TX and flush all packets out, and then call the driver stop().
> Unfortunately there is a failed assumption that even ieee80211_xmit()
> would not be called after stopping TX as __ieee80211_suspend() does
> above.
> 2) Since ieee80211_xmit() is being called even after the driver stop()
> callback it means mac80211 can potentially schedule work. Now the
> new rework on the mac80211 workqueue pushes us to WARN when either
> a driver or mac80211 tried to queue work onto the mac80211 workqueue
> and we're suspended. A new patch from Johannes futher enhances this
> to take into consideration resume so that we can allow drivers / mac80211
> to queue work if we were suspended but now resuming. Even with these
> checks in place I note that currently we do slip work through after
> the driver stop() callback is called and before loacl->suspended is
> set to true. So there seems to be a race here.
>
> The first issue is not so clear to resolve as although we likely do prevent
> the networking core from calling ieee80211_subif_start_xmit() it doesn't
> mean ieee80211_xmit() internally will not be called by other parts of
> mac80211 and indeed I do believe this is what is happening. I'll try
> pin point the exact spot where this happens though, but I'll note though
> that checking for local->suspended will *not* work since we already know
> some work is being queued *and running!* and it wouldn't have if
> local->suspended was true already.

OK, not bad and pretty obvious too -- the issue is __ieee80211_suspend()
will tear down BA sessions and this does require xmit'ing. The only issue
then becomes that of trying to queue work after a driver stop(), that can
be fixed easily and will send a patch next.

Luis

2009-12-23 02:36:18

by Sujith

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

Luis Rodriguez wrote:
> OK I have to go now but I managed to get this working without the
> issue coming up. At this point I am not sure if all of these are
> required but I cherry picked 2 patches from wireless-testing and then
> added 4, one based on sujith's suggestion.
>
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0001-mac80211-fix-resume.patch
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0002-mac80211-fix-WMM-AP-settings-application.patch
>
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0003-ath9k-set-and-restore-ps-prior-to-stop-and-interface.patch
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0004-ath9k-ensure-hardware-is-awake-during-ampdu-TX-actio.patch
>
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0005-ath9k-synch-TX-DMA-buffer-upon-TX-cancelation.patch
> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0006-ath9k-do-not-wake-up-device-if-it-hasn-t-been-starte.patch
>
> Its likely only patch 3, 4, and 6 are the only ones required. In fact
> maybe even 6 will fix it, but I just gotta go so cannot test that. I
> was able to resume about 10 times consecutively which I was unable to
> do before.

Probably lucky. :)
None of the above patches address the issue of allowing configuration requests
after the chip has been shut down.

Can you try this on top of the earlier one I sent out ?

diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
index 419c382..7fdcc6b 100644
--- a/drivers/net/wireless/ath/ath9k/main.c
+++ b/drivers/net/wireless/ath/ath9k/main.c
@@ -2673,6 +2673,11 @@ static int ath9k_config(struct ieee80211_hw *hw, u32 changed)

mutex_lock(&sc->mutex);

+ if (sc->sc_flags & SC_OP_INVALID) {
+ mutex_unlock(&sc->mutex);
+ return 0;
+ }
+
/*
* Leave this as the first check because we need to turn on the
* radio if it was disabled before prior to processing the rest

2009-12-23 12:08:07

by Johannes Berg

Subject: Re: mac80211 suspend corner case (was: Asus eeepc 1008HA suspend issue and mac80211 suspend corner) case

On Tue, 2009-12-22 at 14:30 -0500, Luis R. Rodriguez wrote:

> Johannes, any preferences how to handle this? The patch below avoids
> the Interrupt being turned off but its not enough given that we still
> could be associated according to userspace. If the hardware is
> unresponsive maybe it is best to just let the IRQ go disabled, not
> sure, but its likely not what happens in all cases.
>
> Trimming out the irrelevant parts below.

> http://bombadil.infradead.org/~mcgrof/logs/2.6.31-with-2.6.32-wireless
> /irq-disabled.txt
> >
> > This can be fixed by something like the following:
> >
> > diff --git a/net/mac80211/util.c b/net/mac80211/util.c
> > index e6c08da..63d42fa 100644
> > --- a/net/mac80211/util.c
> > +++ b/net/mac80211/util.c
> > @@ -1031,7 +1031,14 @@ int ieee80211_reconfig(struct ieee80211_local
> *local)
> >
> > /* restart hardware */
> > if (local->open_count) {
> > + /*
> > + * Upon resume hardware can sometimes be goofy due to
> > + * various platform issues, so restarting the device may
> > + * at times not work immediately. Propagate the error.
> > + */
> > res = drv_start(local);
> > + if (res)
> > + return res;
> >
> > ieee80211_led_radio(local, true);
> > }
> >
> > But this isn't enough. And since we cannot exactly talk to hardware
> > we can't try to send a deassoc as harware would be unresponsive. I
> > also don't see us handling such cases before either on cfg80211 or
> > mac80211, so curious what we should do.

Well it seems to me that if the driver determines that the hardware is
unreachable or not responding, it would unregister it from mac80211,
which would clean up all user-visible state, obviously.

The patch above seems ok to me, but basically papers over the problem.
If the start there fails, the driver will have to unregister the hw
since any subsequent start will fail as well.

The way I see it, it's like a USB unplug while suspended/hibernated ...
the driver notices that and remo

johannes

Attachments:

2009-12-23 02:55:16

by Luis R. Rodriguez

Subject: Re: Asus eeepc 1008HA suspend issue and mac80211 suspend corner case

On Tue, Dec 22, 2009 at 6:52 PM, Sujith <[email protected]> wrote:
> Luis Rodriguez wrote:
>> OK I have to go now but I managed to get this working without the
>> issue coming up. At this point I am not sure if all of these are
>> required but I cherry picked 2 patches from wireless-testing and then
>> added 4, one based on sujith's suggestion.
>>
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0001-mac80211-fix-resume.patch
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0002-mac80211-fix-WMM-AP-settings-application.patch
>>
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0003-ath9k-set-and-restore-ps-prior-to-stop-and-interface.patch
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0004-ath9k-ensure-hardware-is-awake-during-ampdu-TX-actio.patch
>>
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0005-ath9k-synch-TX-DMA-buffer-upon-TX-cancelation.patch
>> http://bombadil.infradead.org/~mcgrof/patches/pm-stuff/0006-ath9k-do-not-wake-up-device-if-it-hasn-t-been-starte.patch
>>
>> Its likely only patch 3, 4, and 6 are the only ones required. In fact
>> maybe even 6 will fix it, but I just gotta go so cannot test that. I
>> was able to resume about 10 times consecutively which I was unable to
>> do before.
>
> Probably lucky. :)

Not really, I noticed the interrupts were being set and full sleep->
awake was going on right after ath9k_stop() so I looked for who could
have called that and it was mac80211 calling the config, disabling PS.

> None of the above patches address the issue of allowing configuration requests
> after the chip has been shut down.

Did you see the last one? It turns out its the only config option
passed by mac8021 I've seen so far so my commit log should change.

> Can you try this on top of the earlier one I sent out ?
>
> diff --git a/drivers/net/wireless/ath/ath9k/main.c b/drivers/net/wireless/ath/ath9k/main.c
> index 419c382..7fdcc6b 100644
> --- a/drivers/net/wireless/ath/ath9k/main.c
> +++ b/drivers/net/wireless/ath/ath9k/main.c
> @@ -2673,6 +2673,11 @@ static int ath9k_config(struct ieee80211_hw *hw, u32 changed)
>
>        mutex_lock(&sc->mutex);
>
> +       if (sc->sc_flags & SC_OP_INVALID) {
> +               mutex_unlock(&sc->mutex);
> +               return 0;
> +       }
> +
>        /*
>         * Leave this as the first check because we need to turn on the
>         * radio if it was disabled before prior to processing the rest

That ones busts the resume.

Luis