From mboxrd@z Thu Jan 1 00:00:00 1970 Return-path: Received: from mail-wy0-f174.google.com ([74.125.82.174]:47414 "EHLO mail-wy0-f174.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1755457Ab1I2ISD convert rfc822-to-8bit (ORCPT ); Thu, 29 Sep 2011 04:18:03 -0400 Received: by wyg34 with SMTP id 34so4514wyg.19 for ; Thu, 29 Sep 2011 01:18:02 -0700 (PDT) MIME-Version: 1.0 In-Reply-To: <20110927214245.GA1416@ecki> References: <20110830064137.GA4719@ecki> <14be9f3b-4c91-481d-9e52-f3119659fd59@email.android.com> <20110927214245.GA1416@ecki> Date: Thu, 29 Sep 2011 13:48:02 +0530 Message-ID: (sfid-20110929_101816_615406_3404D483) Subject: Re: ath9k: irq storm after suspend/resume From: Mohammed Shafi To: Clemens Buchacher Cc: linux-wireless@vger.kernel.org, beta992@gmail.com Content-Type: text/plain; charset=ISO-8859-1 Sender: linux-wireless-owner@vger.kernel.org List-ID: On Wed, Sep 28, 2011 at 3:12 AM, Clemens Buchacher wrote: > 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. Clemens thanks for taking time and test it, I wll see if i can find something else. > > 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 > -- shafi