Bug 47831
| Summary: | Long delays when waking up from suspend-to-ram on Gigabyte MB | ||
|---|---|---|---|
| Product: | ACPI | Reporter: | Mehmet Giritli (mehmet) |
| Component: | Power-Sleep-Wake | Assignee: | Aaron Lu (aaron.lu) |
| Status: | CLOSED WILL_NOT_FIX | ||
| Severity: | normal | CC: | alan, info, matthew4196, rui.zhang |
| Priority: | P1 | ||
| Hardware: | All | ||
| OS: | Linux | ||
| Kernel Version: | 3.5.3 | Subsystem: | |
| Regression: | No | Bisected commit-id: | |
| Attachments: |
dmesg
dmesg after resume |
||
|
Description
Mehmet Giritli
2012-09-23 09:51:58 UTC
This appears to be the disk coming back on line taking 15 seconds. 3192.870701] ata16: limiting SATA link speed to 1.5 Gbps [ 3192.870703] ata16: hard resetting link and looks like it's because we have to fall back to lower SATA speed. That points to cabling or drive problems. Fixes are either to set the 1.5Gb limit jumper on the drive, check the cables (but it could be a drive/compat funny), or force the speed with boot options. It'll probably speed your initial boot up the same amount if this is the cause. I don't think there is anything we can "fix" here. Hey alan, can you tell me if there is a way to tell which disk drive ata16 is? How can I find this out? I checked the dmesg but I was not able to.. BTW, I don't have any boot up lag at all. My problems are only with resume from STR. I'm also seeing a similar problem on a Asus G74S laptop running kernel: 3.5.0, although it doesn't report any other problems in dmesg. Here is the ata layout in case that is the problem: ata1: INTEL SSDSA2CW160G3 (SSD) ata2: WDC WD7500BPKT-80PK4T0 (Hard Drive) ata3: MATSHITABD-MLT UJ240AS (blueray drive) [773524.241542] PM: Syncing filesystems ... done. [773524.247028] Freezing user space processes ... (elapsed 0.01 seconds) done. [773524.259663] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done. [773524.270901] Suspending console(s) (use no_console_suspend to debug) [773524.271393] sd 1:0:0:0: [sdb] Synchronizing SCSI cache [773524.271529] sd 0:0:0:0: [sda] Synchronizing SCSI cache [773524.271637] sd 0:0:0:0: [sda] Stopping disk [773524.318265] sd 1:0:0:0: [sdb] Stopping disk [773524.728062] ACPI handle has no context! [773524.924920] PM: suspend of devices complete after 654.643 msecs [773524.925056] PM: late suspend of devices complete after 0.135 msecs [773524.946993] ehci_hcd 0000:00:1d.0: wake-up capability enabled by ACPI [773524.958094] ehci_hcd 0000:00:1a.0: wake-up capability enabled by ACPI [773524.968882] PM: noirq suspend of devices complete after 43.872 msecs [773524.969093] ACPI: Preparing to enter system sleep state S3 [773525.075473] PM: Saving platform NVS memory [773525.076310] Disabling non-boot CPUs ... [773525.092939] CPU 1 is now offline [773525.120872] CPU 2 is now offline [773525.142872] CPU 3 is now offline [773525.166078] CPU 4 is now offline [773525.188798] CPU 5 is now offline [773525.208793] CPU 6 is now offline [773525.226700] CPU 7 is now offline [773525.227116] Extended CMOS year: 2000 [773525.228139] ACPI: Low-level resume complete [773525.228189] PM: Restoring platform NVS memory [773525.228648] Extended CMOS year: 2000 [773525.228670] Enabling non-boot CPUs ... [773525.230884] Booting Node 0 Processor 1 APIC 0x2 [773525.269158] CPU1 is up [773525.269233] Booting Node 0 Processor 2 APIC 0x4 [773525.303120] CPU2 is up [773525.303183] Booting Node 0 Processor 3 APIC 0x6 [773525.342065] CPU3 is up [773525.342120] Booting Node 0 Processor 4 APIC 0x1 [773525.385047] CPU4 is up [773525.385150] Booting Node 0 Processor 5 APIC 0x3 [773525.427052] CPU5 is up [773525.427124] Booting Node 0 Processor 6 APIC 0x5 [773525.470003] CPU6 is up [773525.470075] Booting Node 0 Processor 7 APIC 0x7 [773525.508981] CPU7 is up [773525.515203] ACPI: Waking up from system sleep state S3 [773525.821656] ehci_hcd 0000:00:1a.0: wake-up capability disabled by ACPI [773525.822006] ehci_hcd 0000:00:1d.0: wake-up capability disabled by ACPI [773525.833345] xhci_hcd 0000:04:00.0: Refused to change power state, currently in D3 [773525.844334] xhci_hcd 0000:04:00.0: Refused to change power state, currently in D3 [773525.844575] PM: noirq resume of devices complete after 23.120 msecs [773525.844663] PM: early resume of devices complete after 0.056 msecs [773525.844731] ehci_hcd 0000:00:1a.0: setting latency timer to 64 [773525.844788] ehci_hcd 0000:00:1d.0: setting latency timer to 64 [773525.844803] snd_hda_intel 0000:00:1b.0: irq 46 for MSI/MSI-X [773525.844842] ahci 0000:00:1f.2: setting latency timer to 64 [773525.857232] xhci_hcd 0000:04:00.0: Refused to change power state, currently in D3 [773526.075103] usb 1-1.4: reset high-speed USB device number 5 using ehci_hcd [773526.161916] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300) [773526.163913] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [773526.163935] ata3.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773526.163938] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773526.164364] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [773526.164408] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773526.164410] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773526.165111] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [773526.165140] ata1.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773526.165141] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773526.165410] ata1.00: configured for UDMA/133 [773526.165462] sd 0:0:0:0: [sda] Starting disk [773526.169721] ata3.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773526.169723] ata3.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773526.171614] ata3.00: configured for UDMA/100 [773528.248672] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300) [773528.462319] ata2.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [773528.462467] ata2.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773528.462474] ata2.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773528.502794] ata2.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out [773528.502939] ata2.00: ACPI cmd ef/10:06:00:00:00:a0 (SET FEATURES) succeeded [773528.502945] ata2.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out [773528.506091] ata2.00: configured for UDMA/133 [773528.506246] sd 1:0:0:0: [sdb] Starting disk [773540.636168] PM: resume of devices complete after 14807.981 msecs [773540.636278] Restarting tasks ... done. [773540.645132] video LNXVIDEO:00: Restoring backlight state [773540.852409] microcode: CPU0 sig=0x206a7, pf=0x10, revision=0x28 [773540.855086] microcode: CPU1 sig=0x206a7, pf=0x10, revision=0x15 [773540.856423] microcode: CPU1 updated to revision 0x28, date = 2012-04-24 [773540.856431] microcode: CPU2 sig=0x206a7, pf=0x10, revision=0x15 [773540.858016] microcode: CPU2 updated to revision 0x28, date = 2012-04-24 [773540.858033] microcode: CPU3 sig=0x206a7, pf=0x10, revision=0x15 [773540.859454] microcode: CPU3 updated to revision 0x28, date = 2012-04-24 [773540.859465] microcode: CPU4 sig=0x206a7, pf=0x10, revision=0x15 [773540.861237] microcode: CPU4 updated to revision 0x28, date = 2012-04-24 [773540.861251] microcode: CPU5 sig=0x206a7, pf=0x10, revision=0x15 [773540.862800] microcode: CPU5 updated to revision 0x28, date = 2012-04-24 [773540.862810] microcode: CPU6 sig=0x206a7, pf=0x10, revision=0x15 [773540.864410] microcode: CPU6 updated to revision 0x28, date = 2012-04-24 [773540.864422] microcode: CPU7 sig=0x206a7, pf=0x10, revision=0x15 [773540.865925] microcode: CPU7 updated to revision 0x28, date = 2012-04-24 [773540.865994] microcode: Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba [773540.899265] microcode: Microcode Update Driver: v2.00 removed. [773541.321814] r8169 0000:05:00.0: eth0: link down [773541.321821] r8169 0000:05:00.0: eth0: link down [773541.324673] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [773542.897970] r8169 0000:05:00.0: eth0: link up [773542.906629] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Hello Mehmet, Is there a known kernel version that does not have this problem? And it's quite surprising to see you have so many ata ports :-) Please attach the full dmesg if possible, I need to know what kind of controller this is and what driver you are using for it. Created attachment 87711 [details] dmesg Attaching full dmesg as requested. I feel some additional comments are necessary as well, since I filed the bug. First of all, I am pretty sure now that resume-from-s2r is not caused by my disk drives, despite the error message. I always get the similar error message and yet I don't always get the freeze. I strongly suspect that it is the nvidia display adapter driver that is to blame. I get xorg freezes when gnome-shell starts-up and I am thinking that it is making xorg freeze from time to time when resuming. BTW, I did jumper-limited the drive in question to 1.5 Gbps and still have the error messages. One interesting this about those ata16 error messages is that at boot time ata16 appears to be free (i.e., device appears on some other port) and after resume the device is on ata16. Is this normal? BTW, this is the gear I got: http://www.gigabyte.com/products/product-page.aspx?pid=3258&dl=1#sp Created attachment 87731 [details]
dmesg after resume
This is the rest of the dmesg that I get after resume. It successfully resumed...
> I strongly suspect that it is the nvidia display adapter driver that is to > blame. I get xorg freezes when gnome-shell starts-up and I am thinking that > it is making xorg freeze from time to time when resuming. I think you can try blacklist the nvidia driver to see if freeze happens during suspend/resume. Maybe you can do S3 in console mode, and if you didn't get the console back after resume, you can try to ssh to the system to see if everything is OK. > BTW, I did jumper-limited the drive in question to 1.5 Gbps and still have > the error messages. One interesting this about those ata16 error messages is > that at boot time ata16 appears to be free (i.e., device appears on some > other > port) and after resume the device is on ata16. Is this normal? No, and ata16 doesn't have any disk attached to it; but after system is resumed, it keeps reporting connection change event, which is weird to me. Please attach your lspci result, thanks. 00:00.0 Host bridge: Advanced Micro Devices [AMD] nee ATI RD790 Northbridge only dual slot PCI-e_GFX and HT3 K8 part 00:02.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (external gfx0 port A) 00:04.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (PCI express gpp port A) 00:05.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (PCI express gpp port B) 00:07.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (PCI express gpp port D) 00:09.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (PCI express gpp port E) 00:0a.0 PCI bridge: Advanced Micro Devices [AMD] nee ATI RD790 PCI to PCI bridge (PCI express gpp port F) 00:11.0 SATA controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 SATA Controller [AHCI mode] 00:12.0 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 USB OHCI0 Controller 00:12.1 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0 USB OHCI1 Controller 00:12.2 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 USB EHCI Controller 00:13.0 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 USB OHCI0 Controller 00:13.1 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0 USB OHCI1 Controller 00:13.2 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 USB EHCI Controller 00:14.0 SMBus: Advanced Micro Devices [AMD] nee ATI SBx00 SMBus Controller (rev 3c) 00:14.1 IDE interface: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 IDE Controller 00:14.2 Audio device: Advanced Micro Devices [AMD] nee ATI SBx00 Azalia (Intel HDA) 00:14.3 ISA bridge: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 LPC host controller 00:14.4 PCI bridge: Advanced Micro Devices [AMD] nee ATI SBx00 PCI to PCI Bridge 00:14.5 USB controller: Advanced Micro Devices [AMD] nee ATI SB7x0/SB8x0/SB9x0 USB OHCI2 Controller 00:18.0 Host bridge: Advanced Micro Devices [AMD] Family 10h Processor HyperTransport Configuration 00:18.1 Host bridge: Advanced Micro Devices [AMD] Family 10h Processor Address Map 00:18.2 Host bridge: Advanced Micro Devices [AMD] Family 10h Processor DRAM Controller 00:18.3 Host bridge: Advanced Micro Devices [AMD] Family 10h Processor Miscellaneous Control 00:18.4 Host bridge: Advanced Micro Devices [AMD] Family 10h Processor Link Control 01:00.0 VGA compatible controller: NVIDIA Corporation GT215 [GeForce GT 240] (rev a2) 01:00.1 Audio device: NVIDIA Corporation High Definition Audio Controller (rev a1) 02:00.0 USB controller: NEC Corporation uPD720200 USB 3.0 Host Controller (rev 03) 03:00.0 SATA controller: Marvell Technology Group Ltd. 88SE9128 PCIe SATA 6 Gb/s RAID controller (rev 11) 04:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 03) 05:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 03) 06:00.0 SATA controller: JMicron Technology Corp. JMB363 SATA/IDE Controller (rev 03) 06:00.1 IDE interface: JMicron Technology Corp. JMB363 SATA/IDE Controller (rev 03) 07:07.0 Multimedia controller: Philips Semiconductors SAA7134/SAA7135HL Video Broadcast Decoder (rev 01) 07:0e.0 FireWire (IEEE 1394): Texas Instruments TSB43AB23 IEEE-1394a-2000 Controller (PHY/Link) Hi Mehmet, ata16 belongs to JMicron JMB363 SATA controller, and a quick Google showed this: http://marc.info/?l=linux-ide&m=132593186712274&w=2 And that reporter solved the problem by replacing the hardware... So I think we can involve JMicron people on this. Show, Can you please help? On system resume from S3, there are a lot of connection status change events reported by the sata port, pretty like the bug I attached the link above. Thanks. Hi Mehmet, I'm afraid there is nothing I can do to solve this JMicron controller problem, the people I know of working for JMicron have all gone, I don't know who to contact. I'll close this bug as will_not_fix due to some unknown hardware issue, please feel free to re-open it if you think otherwise. Still seeing this in 3.11 kernel on Gigabyte 890 mobo with Phenom 965 with ATI 5850 video card (no Nvidia!): [Firmware Bug]: cpu 1, try to use APIC500 (LVT offset 0) for vector 0x400, but the register is already in use for vector 0xf9 on another cpu and experiencing long wakeup times. |