Return-path: Received: from bsmtp4.bon.at ([195.3.86.186]:51312 "EHLO bsmtp.bon.at" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1752592Ab1I0Wmv (ORCPT ); Tue, 27 Sep 2011 18:42:51 -0400 Date: Tue, 27 Sep 2011 23:42:45 +0200 From: Clemens Buchacher To: Mohammed Shafi Cc: linux-wireless@vger.kernel.org, beta992@gmail.com Subject: Re: ath9k: irq storm after suspend/resume Message-ID: <20110927214245.GA1416@ecki> (sfid-20110928_004257_600745_131B3D5A) References: <20110830064137.GA4719@ecki> <14be9f3b-4c91-481d-9e52-f3119659fd59@email.android.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii In-Reply-To: Sender: linux-wireless-owner@vger.kernel.org List-ID: Hello Mohammed, On Mon, Sep 26, 2011 at 02:54:18PM +0530, Mohammed Shafi wrote: > > is the issue still seen? any improvement with the attached patch.. I still have the issue. No change with current wl-testing plus your patch. Below dmesg output of: modprobe ath9k debug=0x0000fffb echo mem >/sys/power/state # resume Clemens --- [ 27.575562] ath9k 0000:02:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17 [ 27.577970] ath9k 0000:02:00.0: setting latency timer to 64 [ 27.581405] ath: UNDEFINED -> AWAKE [ 27.581469] ath: serialize_regmode is 0 [ 27.626195] ath: Eeprom VER: 14, REV: 13 [ 27.626199] ath: Initialize ANI [ 27.626203] ath: Enable MIB counters [ 27.626240] ath: Setup TX queue: 9 [ 27.626243] ath: Set queue properties for: 9 [ 27.626248] ath: Setup TX queue: 8 [ 27.626251] ath: Set queue properties for: 8 [ 27.626255] ath: Set queue properties for: 8 [ 27.626259] ath: Reset TX queue: 8 [ 27.626286] ath: tx ok 0x0 err 0x0 desc 0x100 eol 0x100 urn 0x0 [ 27.626290] ath: Setup TX queue: 0 [ 27.626293] ath: Set queue properties for: 0 [ 27.626297] ath: Setup TX queue: 1 [ 27.626300] ath: Set queue properties for: 1 [ 27.626304] ath: Setup TX queue: 2 [ 27.626307] ath: Set queue properties for: 2 [ 27.626310] ath: Setup TX queue: 3 [ 27.626313] ath: Set queue properties for: 3 [ 27.627816] ath: TX streams 1, RX streams: 1 [ 27.627819] ath: EEPROM regdomain: 0x60 [ 27.627822] ath: EEPROM indicates we should expect a direct regpair map [ 27.627828] ath: Country alpha2 being used: 00 [ 27.627830] ath: Regpair used: 0x60 [ 27.627838] ath: tx DMA: 512 buffers 1 desc/buf [ 27.627857] ath: tx DMA map: ffff88006f250000 (54600) -> 6f250000 (54600) [ 27.627891] ath: beacon DMA: 4 buffers 1 desc/buf [ 27.627897] ath: beacon DMA map: ffff88007198d000 (416) -> 7198d000 (416) [ 27.627902] ath: cachelsz 64 rxbufsize 1926 [ 27.627906] ath: rx DMA: 512 buffers 1 desc/buf [ 27.627924] ath: rx DMA map: ffff88006f2b0000 (54600) -> 6f2b0000 (54600) [ 27.629650] ieee80211 phy1: Selected rate control algorithm 'ath9k_rate_control' [ 27.630460] Registered led device: ath9k-phy1 [ 27.630475] ieee80211 phy1: Atheros AR9285 Rev:2 mem=0xffffc90021ba0000, irq=17 [ 43.855411] PM: Syncing filesystems ... done. [ 43.948410] PM: Preparing system for mem sleep [ 43.949937] Freezing user space processes ... (elapsed 0.01 seconds) done. [ 43.963254] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done. [ 43.976527] PM: Entering mem sleep [ 43.976595] Suspending console(s) (use no_console_suspend to debug) [ 43.977193] sd 0:0:0:0: [sda] Synchronizing SCSI cache [ 43.989161] jmb38x_ms 0000:06:00.3: PCI INT B disabled [ 43.989194] sdhci-pci 0000:06:00.0: PCI INT B disabled [ 43.989232] ath: AWAKE -> FULL-SLEEP [ 43.998370] sd 0:0:0:0: [sda] Stopping disk [ 44.196369] snd_hda_intel 0000:00:1b.0: PCI INT A disabled [ 44.608701] PM: suspend of devices complete after 633.019 msecs [ 44.609142] jme 0000:06:00.5: PME# enabled [ 44.609152] jme 0000:06:00.5: wake-up capability enabled by ACPI [ 44.648588] PM: late suspend of devices complete after 39.960 msecs [ 44.648748] ACPI: Preparing to enter system sleep state S3 [ 44.951903] PM: Saving platform NVS memory [ 44.952780] Disabling non-boot CPUs ... [ 44.955081] CPU 1 is now offline [ 45.057696] CPU 2 is now offline [ 45.160822] CPU 3 is now offline [ 45.161227] Extended CMOS year: 2000 [ 45.161461] ACPI: Low-level resume complete [ 45.161521] PM: Restoring platform NVS memory [ 45.161951] Extended CMOS year: 2000 [ 45.161974] Enabling non-boot CPUs ... [ 45.162070] Booting Node 0 Processor 1 APIC 0x4 [ 45.162071] smpboot cpu 1: start_ip = 96000 [ 45.173166] Calibrating delay loop (skipped) already calibrated this CPU [ 45.193433] NMI watchdog enabled, takes one hw-pmu counter. [ 45.193554] CPU1 is up [ 45.193622] Booting Node 0 Processor 2 APIC 0x1 [ 45.193623] smpboot cpu 2: start_ip = 96000 [ 45.194742] Switched to NOHz mode on CPU #1 [ 45.204719] Calibrating delay loop (skipped) already calibrated this CPU [ 45.225042] NMI watchdog enabled, takes one hw-pmu counter. [ 45.225176] CPU2 is up [ 45.225257] Booting Node 0 Processor 3 APIC 0x5 [ 45.225259] smpboot cpu 3: start_ip = 96000 [ 45.228010] Switched to NOHz mode on CPU #2 [ 45.236352] Calibrating delay loop (skipped) already calibrated this CPU [ 45.256763] NMI watchdog enabled, takes one hw-pmu counter. [ 45.256925] CPU3 is up [ 45.258831] Switched to NOHz mode on CPU #3 [ 45.259072] ACPI: Waking up from system sleep state S3 [ 45.580717] intel ips 0000:00:1f.6: MCP limit exceeded: Avg temp 20253, limit 9000 [ 45.658244] i915 0000:00:02.0: restoring config space at offset 0xf (was 0x100, writing 0x10b) [ 45.658253] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407) [ 45.658277] mei 0000:00:16.0: restoring config space at offset 0xf (was 0x100, writing 0x10b) [ 45.658296] mei 0000:00:16.0: restoring config space at offset 0x4 (was 0x4, writing 0xd540a004) [ 45.658304] mei 0000:00:16.0: restoring config space at offset 0x1 (was 0x180000, writing 0x180006) [ 45.658332] pci 0000:00:1a.0: restoring config space at offset 0xf (was 0x100, writing 0x10b) [ 45.658350] pci 0000:00:1a.0: restoring config space at offset 0x4 (was 0x0, writing 0xd5408000) [ 45.658358] pci 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900006) [ 45.658391] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0xf (was 0x100, writing 0x105) [ 45.658410] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x4 (was 0x4, writing 0xd5400004) [ 45.658415] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x3 (was 0x0, writing 0x10) [ 45.658421] snd_hda_intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100004, writing 0x100002) [ 45.658455] pcieport 0000:00:1c.0: restoring config space at offset 0xf (was 0x100, writing 0x10010b) [ 45.658467] pcieport 0000:00:1c.0: restoring config space at offset 0x9 (was 0x1fff1, writing 0x7c717c61) [ 45.658479] pcieport 0000:00:1c.0: restoring config space at offset 0x3 (was 0x810000, writing 0x810010) [ 45.658485] pcieport 0000:00:1c.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100407) [ 45.658538] pcieport 0000:00:1c.1: restoring config space at offset 0xf (was 0x200, writing 0x100203) [ 45.658550] pcieport 0000:00:1c.1: restoring config space at offset 0x9 (was 0x1fff1, writing 0x7c517c41) [ 45.658561] pcieport 0000:00:1c.1: restoring config space at offset 0x3 (was 0x810000, writing 0x810010) [ 45.658568] pcieport 0000:00:1c.1: restoring config space at offset 0x1 (was 0x100000, writing 0x100407) [ 45.658620] pcieport 0000:00:1c.2: restoring config space at offset 0xf (was 0x300, writing 0x100304) [ 45.658632] pcieport 0000:00:1c.2: restoring config space at offset 0x9 (was 0x1fff1, writing 0x7c317c21) [ 45.658643] pcieport 0000:00:1c.2: restoring config space at offset 0x3 (was 0x810000, writing 0x810010) [ 45.658650] pcieport 0000:00:1c.2: restoring config space at offset 0x1 (was 0x100000, writing 0x100407) [ 45.658703] pcieport 0000:00:1c.5: restoring config space at offset 0xf (was 0x200, writing 0x100203) [ 45.658714] pcieport 0000:00:1c.5: restoring config space at offset 0x9 (was 0x1fff1, writing 0x7c117c01) [ 45.658726] pcieport 0000:00:1c.5: restoring config space at offset 0x3 (was 0x810000, writing 0x810010) [ 45.658732] pcieport 0000:00:1c.5: restoring config space at offset 0x1 (was 0x100000, writing 0x100407) [ 45.658780] pci 0000:00:1d.0: restoring config space at offset 0xf (was 0x100, writing 0x10a) [ 45.658799] pci 0000:00:1d.0: restoring config space at offset 0x4 (was 0x0, writing 0xd5407000) [ 45.658807] pci 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900000, writing 0x2900006) [ 45.658831] pci 0000:00:1e.0: restoring config space at offset 0xf (was 0x0, writing 0x100000) [ 45.658930] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407) [ 45.659017] intel ips 0000:00:1f.6: restoring config space at offset 0x1 (was 0x100400, writing 0x100406) [ 45.659057] ath9k 0000:02:00.0: restoring config space at offset 0xf (was 0x1ff, writing 0x103) [ 45.659077] ath9k 0000:02:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xd2c00004) [ 45.659082] ath9k 0000:02:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10) [ 45.659088] ath9k 0000:02:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100007) [ 45.659129] sdhci-pci 0000:06:00.0: restoring config space at offset 0xf (was 0x2ff, writing 0x204) [ 45.659157] sdhci-pci 0000:06:00.0: restoring config space at offset 0x4 (was 0x0, writing 0xd0407000) [ 45.659163] sdhci-pci 0000:06:00.0: restoring config space at offset 0x3 (was 0x800000, writing 0x800010) [ 45.659172] sdhci-pci 0000:06:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100007) [ 45.659218] pci 0000:06:00.2: restoring config space at offset 0xf (was 0x2ff, writing 0x204) [ 45.659246] pci 0000:06:00.2: restoring config space at offset 0x4 (was 0x0, writing 0xd0406000) [ 45.659253] pci 0000:06:00.2: restoring config space at offset 0x3 (was 0x800000, writing 0x800010) [ 45.659262] pci 0000:06:00.2: restoring config space at offset 0x1 (was 0x100000, writing 0x100003) [ 45.659308] jmb38x_ms 0000:06:00.3: restoring config space at offset 0xf (was 0x2ff, writing 0x204) [ 45.659336] jmb38x_ms 0000:06:00.3: restoring config space at offset 0x4 (was 0x0, writing 0xd0405000) [ 45.659342] jmb38x_ms 0000:06:00.3: restoring config space at offset 0x3 (was 0x800000, writing 0x800010) [ 45.659351] jmb38x_ms 0000:06:00.3: restoring config space at offset 0x1 (was 0x100000, writing 0x100007) [ 45.659397] pci 0000:06:00.4: restoring config space at offset 0xf (was 0x2ff, writing 0x204) [ 45.659425] pci 0000:06:00.4: restoring config space at offset 0x4 (was 0x0, writing 0xd0404000) [ 45.659431] pci 0000:06:00.4: restoring config space at offset 0x3 (was 0x800000, writing 0x800010) [ 45.659441] pci 0000:06:00.4: restoring config space at offset 0x1 (was 0x100000, writing 0x100007) [ 45.659487] jme 0000:06:00.5: restoring config space at offset 0xf (was 0x100, writing 0x103) [ 45.659508] jme 0000:06:00.5: restoring config space at offset 0x7 (was 0x1, writing 0xa001) [ 45.659520] jme 0000:06:00.5: restoring config space at offset 0x4 (was 0x0, writing 0xd0400000) [ 45.659526] jme 0000:06:00.5: restoring config space at offset 0x3 (was 0x800000, writing 0x800010) [ 45.659535] jme 0000:06:00.5: restoring config space at offset 0x1 (was 0x100000, writing 0x100007) [ 45.659759] PM: early resume of devices complete after 1.603 msecs [ 45.659979] i915 0000:00:02.0: setting latency timer to 64 [ 45.659996] snd_hda_intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22 [ 45.660003] snd_hda_intel 0000:00:1b.0: setting latency timer to 64 [ 45.660050] snd_hda_intel 0000:00:1b.0: irq 45 for MSI/MSI-X [ 45.660126] pci 0000:00:1e.0: setting latency timer to 64 [ 45.660144] ahci 0000:00:1f.2: setting latency timer to 64 [ 45.660211] ath: FULL-SLEEP -> AWAKE [ 45.663932] sdhci-pci 0000:06:00.0: PCI INT B -> GSI 18 (level, low) -> IRQ 18 [ 45.663974] sdhci-pci 0000:06:00.0: setting latency timer to 64 [ 45.664037] jmb38x_ms 0000:06:00.3: PCI INT B -> GSI 18 (level, low) -> IRQ 18 [ 45.664051] jmb38x_ms 0000:06:00.3: setting latency timer to 64 [ 45.664113] jme 0000:06:00.5: wake-up capability disabled by ACPI [ 45.664124] jme 0000:06:00.5: PME# disabled [ 45.664503] ath: disable IER [ 45.664521] ath: Disable MIB counters [ 45.664560] ath: disable IER [ 45.664575] ath: 0x30 => 0x30 [ 45.664576] ath: new IMR 0x30 [ 45.664672] sd 0:0:0:0: [sda] Starting disk [ 45.667161] ath: Getting spur idx:0 is2Ghz:1 val:8000 [ 45.668810] ath: Reset TX queue: 0 [ 45.668813] ath: tx ok 0x0 err 0x0 desc 0x101 eol 0x101 urn 0x0 [ 45.668815] ath: Reset TX queue: 1 [ 45.668817] ath: tx ok 0x0 err 0x0 desc 0x103 eol 0x103 urn 0x0 [ 45.668819] ath: Reset TX queue: 2 [ 45.668821] ath: tx ok 0x0 err 0x0 desc 0x107 eol 0x107 urn 0x0 [ 45.668823] ath: Reset TX queue: 3 [ 45.668825] ath: tx ok 0x0 err 0x0 desc 0x10f eol 0x10f urn 0x0 [ 45.668827] ath: Reset TXQ, inactive queue: 4 [ 45.668828] ath: Reset TXQ, inactive queue: 5 [ 45.668830] ath: Reset TXQ, inactive queue: 6 [ 45.668831] ath: Reset TXQ, inactive queue: 7 [ 45.668832] ath: Reset TX queue: 8 [ 45.668842] ath: tx ok 0x0 err 0x0 desc 0x10f eol 0x10f urn 0x0 [ 45.668844] ath: Reset TX queue: 9 [ 45.668854] ath: tx ok 0x0 err 0x0 desc 0x10f eol 0x10f urn 0x0 [ 45.668861] ath: ah->misc_mode 0x4 [ 45.670264] ath: Running PA Calibration [ 45.670963] ath: enabling ADC Gain Calibration. [ 45.670964] ath: enabling ADC DC Calibration. [ 45.670965] ath: enabling IQ Calibration. [ 45.670969] ath: starting ADC Gain Calibration [ 45.671139] ath: AWAKE -> FULL-SLEEP [ 45.679552] Extended CMOS year: 2000 [ 45.983193] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [ 45.985133] ata2.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [ 45.985136] ata2.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [ 45.988885] ata2.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [ 45.988889] ata2.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [ 45.989852] ata6: SATA link down (SStatus 0 SControl 300) [ 45.990375] ata2.00: configured for UDMA/100 [ 46.120272] irq 17: nobody cared (try booting with the "irqpoll" option) [ 46.120275] Pid: 0, comm: swapper Tainted: G C 3.1.0-rc7-wl-ARCH3.1.0-rc7-ath9k-debug #2 [ 46.120277] Call Trace: [ 46.120280] [] __report_bad_irq+0x3d/0xe0 [ 46.120290] [] note_interrupt+0x14d/0x210 [ 46.120293] [] handle_irq_event_percpu+0xc9/0x2a0 [ 46.120296] [] handle_irq_event+0x48/0x70 [ 46.120299] [] handle_fasteoi_irq+0x5a/0xe0 [ 46.120303] [] handle_irq+0x22/0x40 [ 46.120308] [] do_IRQ+0x5a/0xe0 [ 46.120312] [] common_interrupt+0x6e/0x6e [ 46.120313] [] ? poll_idle+0x3a/0x80 [ 46.120319] [] ? poll_idle+0x13/0x80 [ 46.120321] [] cpuidle_idle_call+0xc6/0x350 [ 46.120324] [] cpu_idle+0xc9/0x120 [ 46.120328] [] rest_init+0x9b/0xa4 [ 46.120330] [] start_kernel+0x3bf/0x3cc [ 46.120333] [] x86_64_start_reservations+0x132/0x136 [ 46.120336] [] ? early_idt_handlers+0x140/0x140 [ 46.120338] [] x86_64_start_kernel+0x102/0x111 [ 46.120340] handlers: [ 46.120344] [] ath_isr [ 46.120345] Disabling IRQ #17 [ 48.371839] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [ 48.479286] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [ 48.479457] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [ 48.479463] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [ 48.516626] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [ 48.516804] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [ 48.516809] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [ 48.518731] ata1.00: configured for UDMA/133 [ 48.526624] ath: FULL-SLEEP -> AWAKE [ 48.530116] ath: ah->misc_mode 0x4 [ 48.530142] ath: AWAKE -> FULL-SLEEP [ 48.530172] PM: resume of devices complete after 2875.994 msecs [ 48.530607] PM: Finishing wakeup. [ 48.530608] Restarting tasks ... done. [ 48.533504] video LNXVIDEO:02: Restoring backlight state