lkml.org 
[lkml]   [2012]   [Apr]   [12]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    From
    Date
    SubjectRe: 3.4-rc ath9k regression (Re: [ath9k-devel] 3.3.1 ath9k regression)
    Hello Felix,

    On Thu, Apr 12, 2012 at 2:11 PM, Felix Fietkau <nbd@openwrt.org> wrote:
    > On 2012-04-12 5:35 PM, Michael Leun wrote:
    >> On Thu, 12 Apr 2012 16:58:34 +0300
    >> Felipe Contreras <felipe.contreras@gmail.com> wrote:
    >>
    >>> On Thu, Apr 12, 2012 at 4:46 PM, Felix Fietkau <nbd@openwrt.org>
    >>> wrote:
    >>> > On 2012-04-09 5:29 PM, Michael Leun wrote:
    >>> >> On Mon, 9 Apr 2012 19:52:45 +0530
    >>>
    >>> >> Seems obvious to me, that this line
    >>> >>
    >>> >> if (sc->ps_idle && (sc->ps_flags & PS_WAIT_FOR_TX_ACK))
    >>> >>
    >>> >> makes the real difference.
    >>> > Please try this patch with plain 3.3.1 or 3.4-rc2 to see if it fixes
    >>> > this issue:
    >>>
    >>> Nope, not here (3.3.1).
    >>
    >> Also negative for 3.4-rc2, but that SLEEP<>AWAKE noise at the end
    >> stopped. Still need "iwconfig wlan0 essid <myssid>" to make it ping
    >> again (that not included in log below).
    > OK, so my fix is definitely worth submitting, since it gets rid of some
    > unnecessary sleep mode transitions. About the iwconfig command: are you
    > not using wpa_supplicant?
    >
    >> Due to Felipes result and 3.4-rc2 didn't repeat my test with 3.3.1, if
    >> you think it would add useful information I could.
    > Maybe it would be useful to get some more detailed logs from that.
    >

    your patch seems to work for me, with 3.3.1:

    this is the log after I disable/re-enable the interface:

    [ 216.202405] ADDRCONF(NETDEV_UP): wlan0: link is not ready
    [ 219.054925] wlan0: authenticate with 00:26:44:68:e0:6f (try 1)
    [ 219.057190] wlan0: authenticated
    [ 219.069573] wlan0: associate with 00:26:44:68:e0:6f (try 1)
    [ 219.074450] wlan0: RX AssocResp from 00:26:44:68:e0:6f (capab=0x411
    status=0 aid=2)
    [ 219.074454] wlan0: associated
    [ 219.074456] wlan0: moving STA 00:26:44:68:e0:6f to state 1
    [ 219.074458] wlan0: moving STA 00:26:44:68:e0:6f to state 2
    [ 219.075217] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    [ 219.081856] wlan0: moving STA 00:26:44:68:e0:6f to state 3
    [ 229.108248] wlan0: no IPv6 routers present

    and here, after a suspend/resume cycle (whole log):

    [ 369.398982] wlan0: deauthenticating from 00:26:44:68:e0:6f by local
    choice (reason=3)
    [ 369.399147] wlan0: moving STA 00:26:44:68:e0:6f to state 2
    [ 369.399150] wlan0: moving STA 00:26:44:68:e0:6f to state 1
    [ 369.399152] wlan0: moving STA 00:26:44:68:e0:6f to state 0
    [ 369.401292] cfg80211: Calling CRDA to update world regulatory domain
    [ 369.405877] cfg80211: World regulatory domain updated:
    [ 369.405880] cfg80211: (start_freq - end_freq @ bandwidth),
    (max_antenna_gain, max_eirp)
    [ 369.405883] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.405885] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.405887] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.405889] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.405891] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.406014] cfg80211: Calling CRDA for country: CA
    [ 369.407613] cfg80211: Regulatory domain changed to country: CA
    [ 369.407616] cfg80211: (start_freq - end_freq @ bandwidth),
    (max_antenna_gain, max_eirp)
    [ 369.407619] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz),
    (300 mBi, 2700 mBm)
    [ 369.407621] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz),
    (300 mBi, 1700 mBm)
    [ 369.407623] cfg80211: (5250000 KHz - 5330000 KHz @ 40000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.407625] cfg80211: (5490000 KHz - 5710000 KHz @ 40000 KHz),
    (300 mBi, 2000 mBm)
    [ 369.407627] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz),
    (300 mBi, 3000 mBm)
    [ 371.731744] EXT4-fs (sda6): re-mounted. Opts: user_xattr,commit=0
    [ 372.488279] PM: Syncing filesystems ... done.
    [ 372.489375] PM: Preparing system for mem sleep
    [ 372.564163] Freezing user space processes ... (elapsed 0.01 seconds) done.
    [ 372.577275] Freezing remaining freezable tasks ... (elapsed 0.01
    seconds) done.
    [ 372.590611] PM: Entering mem sleep
    [ 372.590679] Suspending console(s) (use no_console_suspend to debug)
    [ 372.591562] sd 0:0:0:0: [sda] Synchronizing SCSI cache
    [ 372.665867] sd 0:0:0:0: [sda] Stopping disk
    [ 373.066866] PM: suspend of devices complete after 476.357 msecs
    [ 373.067057] r8169 0000:05:00.0: wake-up capability enabled by ACPI
    [ 373.080184] xhci_hcd 0000:04:00.0: wake-up capability enabled by ACPI
    [ 373.106870] ehci_hcd 0000:00:1d.0: wake-up capability enabled by ACPI
    [ 373.120272] ehci_hcd 0000:00:1a.0: wake-up capability enabled by ACPI
    [ 373.146778] PM: late suspend of devices complete after 79.995 msecs
    [ 373.147102] ACPI: Preparing to enter system sleep state S3
    [ 373.340070] PM: Saving platform NVS memory
    [ 373.341546] Disabling non-boot CPUs ...
    [ 373.343704] CPU 1 is now offline
    [ 373.446348] CPU 2 is now offline
    [ 373.448352] CPU 3 is now offline
    [ 373.450654] CPU 4 is now offline
    [ 373.552894] CPU 5 is now offline
    [ 373.656106] CPU 6 is now offline
    [ 373.657742] CPU 7 is now offline
    [ 373.657974] Extended CMOS year: 2000
    [ 373.658347] ACPI: Low-level resume complete
    [ 373.658391] PM: Restoring platform NVS memory
    [ 373.658795] Extended CMOS year: 2000
    [ 373.658818] Enabling non-boot CPUs ...
    [ 373.658902] Booting Node 0 Processor 1 APIC 0x2
    [ 373.658904] smpboot cpu 1: start_ip = 99000
    [ 373.670044] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.690386] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.690509] CPU1 is up
    [ 373.690861] Booting Node 0 Processor 2 APIC 0x4
    [ 373.690863] smpboot cpu 2: start_ip = 99000
    [ 373.701999] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.722383] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.722585] CPU2 is up
    [ 373.722955] Booting Node 0 Processor 3 APIC 0x6
    [ 373.722957] smpboot cpu 3: start_ip = 99000
    [ 373.734093] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.754545] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.754777] CPU3 is up
    [ 373.755142] Booting Node 0 Processor 4 APIC 0x1
    [ 373.755144] smpboot cpu 4: start_ip = 99000
    [ 373.766279] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.786723] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.786910] CPU4 is up
    [ 373.787280] Booting Node 0 Processor 5 APIC 0x3
    [ 373.787282] smpboot cpu 5: start_ip = 99000
    [ 373.798418] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.819008] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.819222] CPU5 is up
    [ 373.819584] Booting Node 0 Processor 6 APIC 0x5
    [ 373.819586] smpboot cpu 6: start_ip = 99000
    [ 373.830621] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.851273] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.851474] CPU6 is up
    [ 373.851848] Booting Node 0 Processor 7 APIC 0x7
    [ 373.851850] smpboot cpu 7: start_ip = 99000
    [ 373.862985] Calibrating delay loop (skipped) already calibrated this CPU
    [ 373.883756] NMI watchdog enabled, takes one hw-pmu counter.
    [ 373.883991] CPU7 is up
    [ 373.891785] ACPI: Waking up from system sleep state S3
    [ 374.729481] power_supply BAT0: parent PNP0C0A:00 should not be sleeping
    [ 374.859815] ehci_hcd 0000:00:1a.0: wake-up capability disabled by ACPI
    [ 374.860133] ehci_hcd 0000:00:1d.0: wake-up capability disabled by ACPI
    [ 374.860443] xhci_hcd 0000:04:00.0: wake-up capability disabled by ACPI
    [ 374.860714] PM: early resume of devices complete after 1.101 msecs
    [ 374.860806] i915 0000:00:02.0: setting latency timer to 64
    [ 374.860853] ehci_hcd 0000:00:1a.0: setting latency timer to 64
    [ 374.860925] mei 0000:00:16.0: irq 46 for MSI/MSI-X
    [ 374.860946] ehci_hcd 0000:00:1d.0: setting latency timer to 64
    [ 374.860956] ahci 0000:00:1f.2: setting latency timer to 64
    [ 374.860966] snd_hda_intel 0000:00:1b.0: irq 47 for MSI/MSI-X
    [ 374.860990] r8169 0000:05:00.0: wake-up capability disabled by ACPI
    [ 374.861026] usb usb2: root hub lost power or was reset
    [ 374.861028] usb usb4: root hub lost power or was reset
    [ 375.168783] usb 1-1.1: reset full-speed USB device number 6 using ehci_hcd
    [ 375.185288] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
    [ 375.187053] ata3.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded
    [ 375.187063] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES)
    filtered out
    [ 375.189720] ata3.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded
    [ 375.189730] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES)
    filtered out
    [ 375.190353] ata3.00: configured for UDMA/100
    [ 375.252053] usb 1-1.1: device firmware changed
    [ 376.623683] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
    [ 376.624603] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE
    LOCK) filtered out
    [ 376.624869] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded
    [ 376.624879] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES)
    filtered out
    [ 376.626710] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE
    LOCK) filtered out
    [ 376.626901] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded
    [ 376.626908] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES)
    filtered out
    [ 376.627738] ata1.00: configured for UDMA/133
    [ 376.640442] sd 0:0:0:0: [sda] Starting disk
    [ 376.664962] PM: resume of devices complete after 1806.201 msecs
    [ 376.665192] PM: Finishing wakeup.
    [ 376.665194] Restarting tasks ...
    [ 376.665590] usb 1-1.1: USB disconnect, device number 6
    [ 376.668280] done.
    [ 376.670324] video LNXVIDEO:00: Restoring backlight state
    [ 376.670620] video LNXVIDEO:01: Restoring backlight state
    [ 376.733756] usb 1-1.1: new full-speed USB device number 7 using ehci_hcd
    [ 377.163777] usb 1-1.1: USB disconnect, device number 7
    [ 377.606044] usb 1-1.1: new full-speed USB device number 8 using ehci_hcd
    [ 378.303702] EXT4-fs (sda6): re-mounted. Opts: user_xattr,commit=0
    [ 378.352672] delay: estimated 89, actual 0
    [ 378.376651] delay: estimated 90, actual 1
    [ 378.383106] ADDRCONF(NETDEV_UP): wlan0: link is not ready
    [ 378.525263] r8169 0000:05:00.0: eth0: link down
    [ 378.525835] ADDRCONF(NETDEV_UP): eth0: link is not ready
    [ 381.363952] wlan0: authenticate with 00:26:44:68:e0:6f (try 1)
    [ 381.366409] wlan0: authenticated
    [ 381.378693] wlan0: associate with 00:26:44:68:e0:6f (try 1)
    [ 381.381696] wlan0: RX AssocResp from 00:26:44:68:e0:6f (capab=0x411
    status=0 aid=2)
    [ 381.381699] wlan0: associated
    [ 381.381703] wlan0: moving STA 00:26:44:68:e0:6f to state 1
    [ 381.381704] wlan0: moving STA 00:26:44:68:e0:6f to state 2
    [ 381.382379] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
    [ 381.389476] wlan0: moving STA 00:26:44:68:e0:6f to state 3
    [ 392.289757] wlan0: no IPv6 routers present


    > - Felix


    \
     
     \ /
      Last update: 2012-04-12 21:31    [W:4.527 / U:0.056 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site