Re: Suspend/resume - slow resume
From: Ciprian Docan
Date: Mon Apr 18 2011 - 16:15:36 EST
TOTALLY UNTESTED PATCH ATTACHED!
Ciprian - does this get rid of the 60-second wait? Do you get a nice
kernel traceback in your dmesg instead?
Linus - I applied your patch and attached the diff between output of dmesg
before and after the patch as resume_timing.diff. This patch alone does
not seem to fix the issue; however, applying Francois's patch in addition
to yours make the resume smooth. I have also attached the diff output of
dmesg before and after, with both patched applied as resume2_timing.diff.
Both cases were tested after a fresh reboot. Please let me know if you
need any other information.
Thank you,
--
Ciprian1003a1004,1167
> [ 65.618866] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 65.618883] brcmsmac: wl_ops_bss_info_changed: disassociated
> [ 65.618888] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [ 65.618892] wl_ops_bss_info_changed: short preamble: false (implement)
> [ 65.618903] wl_ops_bss_info_changed: arp filtering: enabled false, count 1 (implement)
> [ 65.618911] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [ 65.642295] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 65.642338] cfg80211: All devices are disconnected, going to restore regulatory settings
> [ 65.642346] cfg80211: Restoring regulatory settings
> [ 65.642356] cfg80211: Calling CRDA to update world regulatory domain
> [ 65.642419] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 65.647025] cfg80211: Updating information on frequency 2412 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647033] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647038] cfg80211: Updating information on frequency 2417 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647043] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647047] cfg80211: Updating information on frequency 2422 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647052] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647056] cfg80211: Updating information on frequency 2427 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647061] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647065] cfg80211: Updating information on frequency 2432 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647070] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647075] cfg80211: Updating information on frequency 2437 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647079] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647084] cfg80211: Updating information on frequency 2442 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647089] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647093] cfg80211: Updating information on frequency 2447 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647098] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647102] cfg80211: Updating information on frequency 2452 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647107] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647111] cfg80211: Updating information on frequency 2457 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647116] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647120] cfg80211: Updating information on frequency 2462 MHz for a 20 MHz width channel with regulatory rule:
> [ 65.647125] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 65.647129] cfg80211: Disabling freq 2467 MHz
> [ 65.647132] cfg80211: Disabling freq 2472 MHz
> [ 65.647135] cfg80211: Disabling freq 2484 MHz
> [ 65.647139] cfg80211: World regulatory domain updated:
> [ 65.647141] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
> [ 65.647146] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 65.647151] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [ 65.647156] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [ 65.647160] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 65.647182] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 65.661205] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 67.149409] PM: Syncing filesystems ... done.
> [ 67.150612] PM: Preparing system for mem sleep
> [ 67.294102] Freezing user space processes ... (elapsed 0.01 seconds) done.
> [ 67.304765] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
> [ 67.315716] PM: Entering mem sleep
> [ 67.315872] Suspending console(s) (use no_console_suspend to debug)
> [ 67.316505] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 67.319105] sd 0:0:0:0: [sda] Stopping disk
> [ 67.355568] brcmsmac 0000:03:00.0: PCI INT A disabled
> [ 67.366638] ehci_hcd 0000:00:1d.0: PCI INT A disabled
> [ 67.366650] ehci_hcd 0000:00:1a.0: PCI INT A disabled
> [ 67.455454] HDA Intel 0000:01:00.1: PCI INT B disabled
> [ 67.455488] ACPI handle has no context!
> [ 67.457872] HDA Intel 0000:00:1b.0: PCI INT A disabled
> [ 69.824037] PM: suspend of devices complete after 2514.601 msecs
> [ 69.824247] r8169 0000:02:00.0: PME# enabled
> [ 69.832945] r8169 0000:02:00.0: wake-up capability enabled by ACPI
> [ 69.865924] PM: late suspend of devices complete after 42.000 msecs
> [ 69.866079] ACPI: Preparing to enter system sleep state S3
> [ 69.911889] PM: Saving platform NVS memory
> [ 69.915560] Disabling non-boot CPUs ...
> [ 69.917358] CPU 1 is now offline
> [ 69.929978] CPU 2 is now offline
> [ 69.931819] Broke affinity for irq 9
> [ 69.932857] CPU 3 is now offline
> [ 69.933182] Extended CMOS year: 2000
> [ 69.933377] ACPI: Low-level resume complete
> [ 69.933432] PM: Restoring platform NVS memory
> [ 69.933979] Extended CMOS year: 2000
> [ 69.934000] Enabling non-boot CPUs ...
> [ 69.934120] Booting Node 0 Processor 1 APIC 0x1
> [ 69.934121] smpboot cpu 1: start_ip = 98000
> [ 70.025135] Switched to NOHz mode on CPU #1
> [ 70.026670] CPU1 is up
> [ 70.026831] Booting Node 0 Processor 2 APIC 0x4
> [ 70.026834] smpboot cpu 2: start_ip = 98000
> [ 70.117565] CPU2 is up
> [ 70.117646] Booting Node 0 Processor 3 APIC 0x5
> [ 70.117648] smpboot cpu 3: start_ip = 98000
> [ 70.117845] Switched to NOHz mode on CPU #2
> [ 70.208157] CPU3 is up
> [ 70.209353] Switched to NOHz mode on CPU #3
> [ 70.209710] ACPI: Waking up from system sleep state S3
> [ 70.277137] pcieport 0000:00:01.0: restoring config space at offset 0x7 (was 0x20003030, writing 0x3030)
> [ 70.277142] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [ 70.277162] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407)
> [ 70.277190] pci 0000:00:16.0: restoring config space at offset 0x1 (was 0x180006, writing 0x100006)
> [ 70.277222] ehci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [ 70.277257] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100002)
> [ 70.277286] pcieport 0000:00:1c.0: restoring config space at offset 0x7 (was 0x20002020, writing 0x2020)
> [ 70.277362] ehci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [ 70.277384] pci 0000:00:1e.0: restoring config space at offset 0xa (was 0xffffffff, writing 0x0)
> [ 70.277465] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
> [ 70.277588] HDA Intel 0000:01:00.1: restoring config space at offset 0x1 (was 0x100007, writing 0x100003)
> [ 70.277642] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [ 70.277728] brcmsmac 0000:03:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
> [ 70.277748] brcmsmac 0000:03:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xc2400004)
> [ 70.277753] brcmsmac 0000:03:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
> [ 70.277759] brcmsmac 0000:03:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100006)
> [ 70.277907] PM: early resume of devices complete after 0.832 msecs
> [ 70.278058] i915 0000:00:02.0: setting latency timer to 64
> [ 70.278063] ehci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
> [ 70.278069] ehci_hcd 0000:00:1a.0: setting latency timer to 64
> [ 70.278084] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
> [ 70.278091] ehci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
> [ 70.278093] HDA Intel 0000:00:1b.0: setting latency timer to 64
> [ 70.278100] ehci_hcd 0000:00:1d.0: setting latency timer to 64
> [ 70.278110] pci 0000:00:1e.0: setting latency timer to 64
> [ 70.278132] ahci 0000:00:1f.2: setting latency timer to 64
> [ 70.278140] HDA Intel 0000:01:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
> [ 70.278145] HDA Intel 0000:01:00.1: setting latency timer to 64
> [ 70.278160] HDA Intel 0000:00:1b.0: irq 46 for MSI/MSI-X
> [ 70.278194] HDA Intel 0000:01:00.1: irq 47 for MSI/MSI-X
> [ 70.278338] sd 0:0:0:0: [sda] Starting disk
> [ 70.278461] brcmsmac 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
> [ 70.278467] brcmsmac 0000:03:00.0: setting latency timer to 64
> [ 70.286439] r8169 0000:02:00.0: wake-up capability disabled by ACPI
> [ 70.286445] r8169 0000:02:00.0: PME# disabled
> [ 70.508985] usb 1-1.4: reset full speed USB device number 3 using ehci_hcd
> [ 70.583638] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> [ 70.585644] ata5: SATA link down (SStatus 0 SControl 300)
> [ 70.617518] ata2.00: configured for UDMA/100
> [ 70.666598] usb 2-1.3: reset full speed USB device number 3 using ehci_hcd
> [ 70.753366] btusb 2-1.3:1.0: no reset_resume for driver btusb?
> [ 70.753372] btusb 2-1.3:1.1: no reset_resume for driver btusb?
> [ 70.824183] usb 2-1.6: reset high speed USB device number 5 using ehci_hcd
> [ 71.753512] hci_cmd_timer: hci0 command tx timeout
> [ 73.023083] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
> [ 73.035133] ata1.00: configured for UDMA/133
> [ 73.642069] PM: resume of devices complete after 3373.220 msecs
> [ 73.642418] PM: Finishing wakeup.
> [ 73.642420] Restarting tasks ... done.
> [ 73.648564] video LNXVIDEO:00: Restoring backlight state
> [ 73.648712] video LNXVIDEO:01: Restoring backlight state
> [ 74.082737] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [ 74.082742] wl_ops_bss_info_changed: short preamble: false (implement)
> [ 74.082760] wl_ops_config: change monitor mode: false (implement)
> [ 74.082763] wl_ops_config: change power-save mode: false (implement)
> [ 74.084986] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 74.085682] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 74.085702] ADDRCONF(NETDEV_UP): wlan0: link is not ready
> [ 74.174940] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 74.174977] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 74.264656] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 74.293752] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 74.293812] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [ 74.383350] wlan0: authenticate with 00:1c:10:9c:3c:98 (try 1)
> [ 74.398331] wlan0: authenticated
> [ 74.398347] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 74.398374] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 74.398381] wlan0: associate with 00:1c:10:9c:3c:98 (try 1)
> [ 74.402842] wlan0: RX AssocResp from 00:1c:10:9c:3c:98 (capab=0x411 status=0 aid=11)
> [ 74.402846] wlan0: associated
> [ 74.403886] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 74.403891] brcmsmac: wl_ops_bss_info_changed: associated
> [ 74.403898] wl_ops_bss_info_changed: Need to change Basic Rates: 0xf (implement)
> [ 74.403904] wl_ops_bss_info_changed: arp filtering: enabled true, count 0 (implement)
> [ 74.405021] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
> [ 74.647583] hci_cmd_timer: hci0 command tx timeout
> [ 74.776522] wl_ops_bss_info_changed: arp filtering: enabled true, count 1 (implement)
1031a1032,1197
> [ 75.923864] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 75.923874] brcmsmac: wl_ops_bss_info_changed: disassociated
> [ 75.923877] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [ 75.923880] wl_ops_bss_info_changed: short preamble: false (implement)
> [ 75.923889] wl_ops_bss_info_changed: arp filtering: enabled false, count 1 (implement)
> [ 75.923895] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [ 75.943322] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 75.943339] cfg80211: All devices are disconnected, going to restore regulatory settings
> [ 75.943348] cfg80211: Restoring regulatory settings
> [ 75.943357] cfg80211: Calling CRDA to update world regulatory domain
> [ 75.943362] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 75.948033] cfg80211: Updating information on frequency 2412 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948041] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948046] cfg80211: Updating information on frequency 2417 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948051] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948055] cfg80211: Updating information on frequency 2422 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948060] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948065] cfg80211: Updating information on frequency 2427 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948069] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948074] cfg80211: Updating information on frequency 2432 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948079] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948083] cfg80211: Updating information on frequency 2437 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948088] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948092] cfg80211: Updating information on frequency 2442 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948097] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948101] cfg80211: Updating information on frequency 2447 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948106] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948110] cfg80211: Updating information on frequency 2452 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948115] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948119] cfg80211: Updating information on frequency 2457 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948124] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948149] cfg80211: Updating information on frequency 2462 MHz for a 20 MHz width channel with regulatory rule:
> [ 75.948154] cfg80211: 2402000 KHz - 2472000 KHz @ KHz), (300 mBi, 2700 mBm)
> [ 75.948157] cfg80211: Disabling freq 2467 MHz
> [ 75.948160] cfg80211: Disabling freq 2472 MHz
> [ 75.948163] cfg80211: Disabling freq 2484 MHz
> [ 75.948167] cfg80211: World regulatory domain updated:
> [ 75.948170] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
> [ 75.948175] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 75.948180] cfg80211: (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [ 75.948185] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [ 75.948189] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 75.948194] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [ 75.957206] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 77.705556] PM: Syncing filesystems ... done.
> [ 77.706722] PM: Preparing system for mem sleep
> [ 77.850189] Freezing user space processes ... (elapsed 0.01 seconds) done.
> [ 77.861052] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
> [ 77.872039] PM: Entering mem sleep
> [ 77.872191] Suspending console(s) (use no_console_suspend to debug)
> [ 77.872837] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 77.888620] sd 0:0:0:0: [sda] Stopping disk
> [ 77.912060] brcmsmac 0000:03:00.0: PCI INT A disabled
> [ 77.923064] ehci_hcd 0000:00:1d.0: PCI INT A disabled
> [ 77.923076] ehci_hcd 0000:00:1a.0: PCI INT A disabled
> [ 78.013092] HDA Intel 0000:01:00.1: PCI INT B disabled
> [ 78.013126] ACPI handle has no context!
> [ 78.014369] HDA Intel 0000:00:1b.0: PCI INT A disabled
> [ 80.399749] PM: suspend of devices complete after 2527.459 msecs
> [ 80.399924] r8169 0000:02:00.0: PME# enabled
> [ 80.408697] r8169 0000:02:00.0: wake-up capability enabled by ACPI
> [ 80.441740] PM: late suspend of devices complete after 41.997 msecs
> [ 80.441884] ACPI: Preparing to enter system sleep state S3
> [ 80.487834] PM: Saving platform NVS memory
> [ 80.493177] Disabling non-boot CPUs ...
> [ 80.494806] CPU 1 is now offline
> [ 80.496529] CPU 2 is now offline
> [ 80.504829] Broke affinity for irq 20
> [ 80.505876] CPU 3 is now offline
> [ 80.506220] Extended CMOS year: 2000
> [ 80.506416] ACPI: Low-level resume complete
> [ 80.506471] PM: Restoring platform NVS memory
> [ 80.507040] Extended CMOS year: 2000
> [ 80.507079] Enabling non-boot CPUs ...
> [ 80.507182] Booting Node 0 Processor 1 APIC 0x1
> [ 80.507183] smpboot cpu 1: start_ip = 98000
> [ 80.598507] Switched to NOHz mode on CPU #1
> [ 80.599960] CPU1 is up
> [ 80.600052] Booting Node 0 Processor 2 APIC 0x4
> [ 80.600053] smpboot cpu 2: start_ip = 98000
> [ 80.691078] CPU2 is up
> [ 80.691178] Booting Node 0 Processor 3 APIC 0x5
> [ 80.691180] smpboot cpu 3: start_ip = 98000
> [ 80.691471] Switched to NOHz mode on CPU #2
> [ 80.782157] CPU3 is up
> [ 80.783357] Switched to NOHz mode on CPU #3
> [ 80.783681] ACPI: Waking up from system sleep state S3
> [ 80.851177] pcieport 0000:00:01.0: restoring config space at offset 0x7 (was 0x20003030, writing 0x3030)
> [ 80.851181] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [ 80.851201] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407)
> [ 80.851229] pci 0000:00:16.0: restoring config space at offset 0x1 (was 0x180006, writing 0x100006)
> [ 80.851262] ehci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [ 80.851297] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100002)
> [ 80.851327] pcieport 0000:00:1c.0: restoring config space at offset 0x7 (was 0x20002020, writing 0x2020)
> [ 80.851402] ehci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [ 80.851424] pci 0000:00:1e.0: restoring config space at offset 0xa (was 0xffffffff, writing 0x0)
> [ 80.851504] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
> [ 80.851627] HDA Intel 0000:01:00.1: restoring config space at offset 0x1 (was 0x100007, writing 0x100003)
> [ 80.851680] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [ 80.851768] brcmsmac 0000:03:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
> [ 80.851787] brcmsmac 0000:03:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xc2400004)
> [ 80.851792] brcmsmac 0000:03:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
> [ 80.851798] brcmsmac 0000:03:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100006)
> [ 80.851949] PM: early resume of devices complete after 0.833 msecs
> [ 80.852100] i915 0000:00:02.0: setting latency timer to 64
> [ 80.852107] ehci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
> [ 80.852113] ehci_hcd 0000:00:1a.0: setting latency timer to 64
> [ 80.852148] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
> [ 80.852152] HDA Intel 0000:00:1b.0: setting latency timer to 64
> [ 80.852191] HDA Intel 0000:00:1b.0: irq 46 for MSI/MSI-X
> [ 80.852231] ehci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
> [ 80.852236] ehci_hcd 0000:00:1d.0: setting latency timer to 64
> [ 80.852265] pci 0000:00:1e.0: setting latency timer to 64
> [ 80.852277] ahci 0000:00:1f.2: setting latency timer to 64
> [ 80.852326] HDA Intel 0000:01:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
> [ 80.852330] HDA Intel 0000:01:00.1: setting latency timer to 64
> [ 80.852363] HDA Intel 0000:01:00.1: irq 47 for MSI/MSI-X
> [ 80.852480] brcmsmac 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
> [ 80.852485] brcmsmac 0000:03:00.0: setting latency timer to 64
> [ 80.852598] sd 0:0:0:0: [sda] Starting disk
> [ 80.865473] r8169 0000:02:00.0: wake-up capability disabled by ACPI
> [ 80.865479] r8169 0000:02:00.0: PME# disabled
> [ 81.083607] usb 1-1.4: reset full speed USB device number 3 using ehci_hcd
> [ 81.158479] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> [ 81.160479] ata5: SATA link down (SStatus 0 SControl 300)
> [ 81.192446] ata2.00: configured for UDMA/100
> [ 81.241617] usb 2-1.3: reset full speed USB device number 3 using ehci_hcd
> [ 81.328714] btusb 2-1.3:1.0: no reset_resume for driver btusb?
> [ 81.328719] btusb 2-1.3:1.1: no reset_resume for driver btusb?
> [ 81.399752] usb 2-1.6: reset high speed USB device number 5 using ehci_hcd
> [ 82.329405] hci_cmd_timer: hci0 command tx timeout
> [ 83.604299] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
> [ 83.616192] ata1.00: configured for UDMA/133
> [ 141.955556] r8169 0000:02:00.0: eth0: unable to apply firmware patch
> [ 142.557969] PM: resume of devices complete after 61712.246 msecs
> [ 142.558474] PM: Finishing wakeup.
> [ 142.558475] Restarting tasks ... done.
> [ 142.563742] video LNXVIDEO:00: Restoring backlight state
> [ 142.563923] video LNXVIDEO:01: Restoring backlight state
> [ 143.565055] hci_cmd_timer: hci0 command tx timeout
> [ 143.591177] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [ 143.591183] wl_ops_bss_info_changed: short preamble: false (implement)
> [ 143.591202] wl_ops_config: change monitor mode: false (implement)
> [ 143.591205] wl_ops_config: change power-save mode: false (implement)
> [ 143.593448] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 143.594031] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 143.594061] ADDRCONF(NETDEV_UP): wlan0: link is not ready
> [ 143.684097] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 143.684157] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 143.774118] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 143.798174] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 143.798222] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [ 143.888109] wlan0: authenticate with 00:1c:10:9c:3c:98 (try 1)
> [ 143.911758] wlan0: authenticated
> [ 143.911781] wl_ops_bss_info_changed: BSS idle: true (implement)
> [ 143.911815] wl_ops_bss_info_changed: BSS idle: false (implement)
> [ 143.911821] wlan0: associate with 00:1c:10:9c:3c:98 (try 1)
> [ 143.914372] wlan0: RX AssocResp from 00:1c:10:9c:3c:98 (capab=0x411 status=0 aid=11)
> [ 143.914377] wlan0: associated
> [ 143.915137] wl_ops_bss_info_changed: qos enabled: false (implement)
> [ 143.915141] brcmsmac: wl_ops_bss_info_changed: associated
> [ 143.915147] wl_ops_bss_info_changed: Need to change Basic Rates: 0xf (implement)
> [ 143.915153] wl_ops_bss_info_changed: arp filtering: enabled true, count 0 (implement)
> [ 143.915987] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
> [ 143.974405] wl_ops_bss_info_changed: arp filtering: enabled true, count 1 (implement)
> [ 154.004056] wlan0: no IPv6 routers present