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

["Luis R. Rodriguez" <lrodriguez@atheros.com>]

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